[2020-08-18 09:51:27] VERBOSE[28564] chan_sip.c: [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 0 [ 68]: INVITE sip:+492018533416@customer.opennumbers.net;user=phone SIP/2.0 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 1 [ 79]: Via: SIP/2.0/UDP 46.182.254.135:5060;branch=z9hG4bK00E0F515158AAFB00C6F2BEABD46 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 2 [137]: From: "+420595626958" ;tag=0UUHS0000030000E1D0101Cu047PC2D06J9VQV [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 3 [ 89]: To: "+492018533416" [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 4 [ 59]: Call-ID: 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 5 [ 18]: CSeq: 45177 INVITE [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 6 [115]: Contact: [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 7 [ 19]: Allow-Events: refer [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 8 [ 87]: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, INFO, REFER, NOTIFY, SUBSCRIBE, UPDATE [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 10 [ 16]: Max-Forwards: 70 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 11 [106]: P-Asserted-Identity: [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 12 [ 69]: P-Preferred-Identity: [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 13 [ 13]: Privacy: none [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 14 [ 44]: Supported: timer, replaces, histinfo, 100rel [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 15 [ 21]: User-Agent: TELES-SBC [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 16 [ 19]: Content-Length: 226 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 17 [ 0]: [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Body 0 [ 3]: v=0 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Body 1 [ 47]: o=- 2631957580778647339 1 IN IP4 46.182.254.135 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Body 2 [ 11]: s=TELES-SBC [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Body 3 [ 23]: c=IN IP4 46.182.254.137 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Body 4 [ 5]: t=0 0 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Body 5 [ 26]: m=audio 41426 RTP/AVP 8 96 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Body 7 [ 32]: a=rtpmap:96 telephone-event/8000 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Body 8 [ 14]: a=fmtp:96 0-15 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Body 9 [ 25]: a=silenceSupp:off - - - - [2020-08-18 09:51:27] VERBOSE[28564] chan_sip.c: --- (17 headers 10 lines) --- [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: = Looking for Call ID: 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 (Checking From) --From tag 0UUHS0000030000E1D0101Cu047PC2D06J9VQV --To-tag [2020-08-18 09:51:27] DEBUG[28564] acl.c: For destination '46.182.254.135', our source address is '93.159.248.39'. [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Setting AST_TRANSPORT_UDP with address 93.159.248.39:5060 [2020-08-18 09:51:27] DEBUG[28564] netsock2.c: Splitting '46.182.254.135:5060' into... [2020-08-18 09:51:27] DEBUG[28564] netsock2.c: ...host '46.182.254.135' and port '5060'. [2020-08-18 09:51:27] VERBOSE[28564] chan_sip.c: Sending to 46.182.254.135:5060 (no NAT) [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Allocating new SIP dialog for 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 - INVITE (No RTP) [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] sip/reqresp_parser.c: Begin: parsing SIP "Supported: timer, replaces, histinfo, 100rel" [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] sip/reqresp_parser.c: Found SIP option: -timer- [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] sip/reqresp_parser.c: Matched SIP option: timer [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] sip/reqresp_parser.c: Found SIP option: -replaces- [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] sip/reqresp_parser.c: Matched SIP option: replaces [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] sip/reqresp_parser.c: Found SIP option: -histinfo- [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] sip/reqresp_parser.c: Matched SIP option: histinfo [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] sip/reqresp_parser.c: Found SIP option: -100rel- [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] sip/reqresp_parser.c: Matched SIP option: 100rel [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '46.182.254.135:5060' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '46.182.254.135' and port '5060'. [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] chan_sip.c: Sending to 46.182.254.135:5060 (no NAT) [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Initializing initreq for method INVITE - callid 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] chan_sip.c: Using INVITE request as basis request - 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting 'mgc-cluster.opennumbers.net' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host 'mgc-cluster.opennumbers.net' and port ''. [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] chan_sip.c: Found peer 'opennumbers_equada2' for '+420595626958' from 46.182.254.135:5060 [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7faefb4ea910' [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] res_rtp_asterisk.c: Allocated port 19578 for RTP instance '0x7faefb4ea910' [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] res_rtp_asterisk.c: Creating ICE session [::]:19578 (19578) for RTP instance '0x7faefb4ea910' [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '10.33.0.1' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '10.33.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '93.159.248.39' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '93.159.248.39' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '93.159.248.43' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '93.159.248.43' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '10.2.0.1' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '10.2.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '10.8.0.1' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '10.8.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '10.50.0.1' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '10.50.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '10.12.0.1' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '10.12.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '10.16.0.1' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '10.16.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '10.55.0.1' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '10.55.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '10.0.1.1' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '10.0.1.1' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '2a00:fe0:1:23::100' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '2a00:fe0:1:23::100' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '2a00:fe0:1:23:5054:ff:fe00:13b' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '2a00:fe0:1:23:5054:ff:fe00:13b' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:13b' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:13b' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:13c' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:13c' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:13d' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:13d' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:13e' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:13e' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:13f' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:13f' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:140' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:140' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:141' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:141' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:142' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:142' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] rtp_engine.c: RTP instance '0x7faefb4ea910' is setup and ready to go [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting 'sip.relaix.net' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host 'sip.relaix.net' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7faefb4ea910' [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] netsock2.c: Using SIP RTP TOS bits 184 [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] netsock2.c: Using SIP RTP TOS bits 184 in TCLASS field. [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] netsock2.c: Using SIP RTP CoS mark 5 [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Setting NAT on RTP to Off [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] chan_sip.c: Got SDP version 1 and unique parts [- 2631957580778647339 IN IP4 46.182.254.135] [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Processing session-level SDP o=- 2631957580778647339 1 IN IP4 46.182.254.135... OK. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Processing session-level SDP s=TELES-SBC... UNSUPPORTED OR FAILED. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting '46.182.254.137' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host '46.182.254.137' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Processing session-level SDP c=IN IP4 46.182.254.137... OK. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] chan_sip.c: Found RTP audio format 8 [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7faf3ad890f0 [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] chan_sip.c: Found RTP audio format 96 [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] chan_sip.c: Found audio description format PCMA for ID 8 [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] chan_sip.c: Found audio description format telephone-event for ID 96 [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:96 telephone-event/8000... OK. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Processing media-level (audio) SDP a=fmtp:96 0-15... UNSUPPORTED OR FAILED. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Processing media-level (audio) SDP a=silenceSupp:off - - - -... UNSUPPORTED OR FAILED. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] rtp_engine.c: Crossover copying tx to rx payload mapping 8 (0x7faefb788b28) from 0x7faf3ad890f0 to 0x7faf3ad890f0 [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] rtp_engine.c: Crossover copying tx to rx payload mapping 96 (0x7faefadf9f18) from 0x7faf3ad890f0 to 0x7faf3ad890f0 [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] chan_sip.c: Capabilities: us - (g722|alaw), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw) [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] acl.c: For destination '46.182.254.137', our source address is '93.159.248.39'. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7faefb4ea910' [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] chan_sip.c: Peer audio RTP is at port 46.182.254.137:41426 [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] rtp_engine.c: Copying rx payload mapping 8 (0x7faefb788b28) from 0x7faf3ad890f0 to 0x7faefb4eaae8 [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] rtp_engine.c: Copying rx payload mapping 96 (0x7faefadf9f18) from 0x7faf3ad890f0 to 0x7faefb4eaae8 [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] rtp_engine.c: Copying tx payload mapping 8 (0x7faefb788b28) from 0x7faf3ad890f0 to 0x7faefb4eaae8 [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] rtp_engine.c: Copying tx payload mapping 96 (0x7faefadf9f18) from 0x7faf3ad890f0 to 0x7faefb4eaae8 [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7faefb4ea910' [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: We're settling with these formats: (alaw) [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Checking SIP call limits for device [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Updating call counter for incoming call [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting 'customer.opennumbers.net' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host 'customer.opennumbers.net' and port ''. [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: Splitting 'mgc-cluster.opennumbers.net' into... [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] netsock2.c: ...host 'mgc-cluster.opennumbers.net' and port ''. [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] chan_sip.c: Looking for +492018533416 in inbound_opennumbers (domain customer.opennumbers.net) [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Incoming INVITE with 'timer' option supported [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] stasis.c: Creating topic. name: channel:1597737087.1466171, detail: [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] stasis.c: Topic 'channel:1597737087.1466171': 0x7faefb446df0 created [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] stasis.c: Creating topic. name: cache:1769366/channel:1597737087.1466171, detail: [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] stasis.c: Topic 'cache:1769366/channel:1597737087.1466171': 0x7faefab7c9a0 created [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] channel.c: Channel 0x7faefb629c50 'SIP/opennumbers_equada2-000e0185' allocated [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: *** Our native formats are (alaw) [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: *** Joint capabilities are (alaw) [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: *** Our capabilities are (g722|alaw) [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: This channel will not be able to handle video. [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] sip/route.c: sip_route_dump: route/path hop: [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: SIP/opennumbers_equada2-000e0185: New call is still down.... Trying... [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] chan_sip.c: [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 46.182.254.135:5060 [2020-08-18 09:51:27] DEBUG[28530] devicestate.c: No provider found, checking channel drivers for SIP - opennumbers_equada2 [2020-08-18 09:51:27] DEBUG[28530] chan_sip.c: Checking device state for peer opennumbers_equada2 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'EXTEN' is '+492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Goto' [2020-08-18 09:51:27] DEBUG[28530] devicestate.c: Changing state for SIP/opennumbers_equada2 - state 1 (Not in use) [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [+492018533416@inbound_opennumbers:1] Goto("SIP/opennumbers_equada2-000e0185", "00492018533416,1") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (inbound_opennumbers,00492018533416,1) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function CALLERID(number) result is '+420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'EXTEN' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function SIP_HEADER(P-Asserted-Identity) result is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function SIP_HEADER(Privacy) result is 'none' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function SIP_HEADER(X-TAS-Served-Identity) result is '(null)' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function SIP_HEADER(P-Access-Network-Info) result is '(null)' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function SIP_HEADER(P-Visited-Network-ID) result is '(null)' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function SIP_HEADER(P-Charging-Function-Addresses) result is '(null)' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:1] NoOp("SIP/opennumbers_equada2-000e0185", "Inboundcall von OpenNumbers: Von=+420595626958 An=00492018533416, P-Asserted-Identity=, Privacy=none, X-TAS-Served-Identity=, P-Access-Network-Info=, P-Visited-Network-ID=, P-Charging-Function-Addresses=") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:2] Set("SIP/opennumbers_equada2-000e0185", "DIAL_CID=show") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function SIP_HEADER(Privacy) result is 'none' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] func_strings.c: FUNCTION REGEX (id)(xnone) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function REGEX("id" xnone) result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:3] GotoIf("SIP/opennumbers_equada2-000e0185", "0?:SrcFormat") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (inbound_opennumbers,00492018533416,6) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function CALLERID(number) result is '+420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Gosub' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:6] Gosub("SIP/opennumbers_equada2-000e0185", "gosub-normalize_number,s,1(+420595626958)") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Channel SIP/opennumbers_equada2-000e0185 has no datastore, so we're allocating one. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG1' to '+420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:1] Set("SIP/opennumbers_equada2-000e0185", "NormNumber=") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is '+420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function ISNULL(+420595626958) result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:2] GotoIf("SIP/opennumbers_equada2-000e0185", "0?:UseArg") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-normalize_number,s,5) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is '+420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:5] Set("SIP/opennumbers_equada2-000e0185", "NormNumber=+420595626958") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'NormNumber' is '+420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:6] GotoIf("SIP/opennumbers_equada2-000e0185", "1?:CheckInt") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'NormNumber' is '+420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:7] Set("SIP/opennumbers_equada2-000e0185", "NormNumber=00420595626958") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is NULL [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function ISNULL() result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:8] GotoIf("SIP/opennumbers_equada2-000e0185", "1?Finish:") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-normalize_number,s,11) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'NormNumber' is '00420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:11] NoOp("SIP/opennumbers_equada2-000e0185", "normierte Nummer: 00420595626958") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Return' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:12] Return("SIP/opennumbers_equada2-000e0185", "") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'NormNumber' is '00420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:7] Set("SIP/opennumbers_equada2-000e0185", "CALLERID(number)=00420595626958") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:8] Set("SIP/opennumbers_equada2-000e0185", "CALLERID(name)=") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'EXTEN' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Gosub' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:9] Gosub("SIP/opennumbers_equada2-000e0185", "gosub-normalize_number,s,1(00492018533416)") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG1' to '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:1] Set("SIP/opennumbers_equada2-000e0185", "NormNumber=") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function ISNULL(00492018533416) result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:2] GotoIf("SIP/opennumbers_equada2-000e0185", "0?:UseArg") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-normalize_number,s,5) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:5] Set("SIP/opennumbers_equada2-000e0185", "NormNumber=00492018533416") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'NormNumber' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:6] GotoIf("SIP/opennumbers_equada2-000e0185", "0?:CheckInt") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-normalize_number,s,8) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is NULL [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function ISNULL() result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:8] GotoIf("SIP/opennumbers_equada2-000e0185", "1?Finish:") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-normalize_number,s,11) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'NormNumber' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:11] NoOp("SIP/opennumbers_equada2-000e0185", "normierte Nummer: 00492018533416") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Return' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-normalize_number:12] Return("SIP/opennumbers_equada2-000e0185", "") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'NormNumber' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:10] Set("SIP/opennumbers_equada2-000e0185", "Zielnummer=00492018533416") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'SIPRemoveHeader' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:11] SIPRemoveHeader("SIP/opennumbers_equada2-000e0185", "X-TAS-Served-Identity:") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'SIPRemoveHeader' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:12] SIPRemoveHeader("SIP/opennumbers_equada2-000e0185", "P-Access-Network-Info:") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'SIPRemoveHeader' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:13] SIPRemoveHeader("SIP/opennumbers_equada2-000e0185", "P-Visited-Network-ID:") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'SIPRemoveHeader' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:14] SIPRemoveHeader("SIP/opennumbers_equada2-000e0185", "P-Charging-Function-Addresses:") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:15] Set("SIP/opennumbers_equada2-000e0185", "CHANNEL(amaflags)=omit") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:16] Set("SIP/opennumbers_equada2-000e0185", "CDR(RxOrigin)=remote") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'Zielnummer' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:17] Set("SIP/opennumbers_equada2-000e0185", "CDR(RxDst)=00492018533416") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function CALLERID(number) result is '00420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:18] Set("SIP/opennumbers_equada2-000e0185", "CDR(RxSrc)=00420595626958") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:19] Set("SIP/opennumbers_equada2-000e0185", "CHANNEL(accountcode)=") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'Zielnummer' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function DIALPLAN_EXISTS(routing_intern,00492018533416,1) result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:20] GotoIf("SIP/opennumbers_equada2-000e0185", "1?DoRouting:") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (inbound_opennumbers,00492018533416,23) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'Zielnummer' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Goto' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@inbound_opennumbers:23] Goto("SIP/opennumbers_equada2-000e0185", "routing_intern,00492018533416,1") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (routing_intern,00492018533416,1) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@routing_intern:1] Set("SIP/opennumbers_equada2-000e0185", "Peerstring="SIP/trunk_101334_essen"") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@routing_intern:2] GotoIf("SIP/opennumbers_equada2-000e0185", "1?:DoMapping") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'EXTEN' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Gosub' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@routing_intern:3] Gosub("SIP/opennumbers_equada2-000e0185", "gosub-convert_number,s,1(00492018533416,3,0049,)") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG1' to '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG2' to '3' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG3' to '0049' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG4' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:1] Set("SIP/opennumbers_equada2-000e0185", "ConvNumber=00492018533416") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '3' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG3' is '0049' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG4' is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:2] NoOp("SIP/opennumbers_equada2-000e0185", "konvertiere Nummer 00492018533416 in Format 3, Int=0049, Nat=") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ConvNumber' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:3] GotoIf("SIP/opennumbers_equada2-000e0185", "1?CheckFormat:") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-convert_number,s,6) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '3' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:6] GotoIf("SIP/opennumbers_equada2-000e0185", "0?Doppelnull:") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '3' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:7] GotoIf("SIP/opennumbers_equada2-000e0185", "0?E164:") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '3' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:8] GotoIf("SIP/opennumbers_equada2-000e0185", "1?E164plus:") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-convert_number,s,14) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ConvNumber' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:14] Set("SIP/opennumbers_equada2-000e0185", "ConvNumber=+492018533416") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ConvNumber' is '+492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:15] NoOp("SIP/opennumbers_equada2-000e0185", "Nummer nach E164+ konvertiert: +492018533416") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Return' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:16] Return("SIP/opennumbers_equada2-000e0185", "") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ConvNumber' is '+492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@routing_intern:4] Set("SIP/opennumbers_equada2-000e0185", "Peerstring="SIP/+492018533416@trunk_101334_essen"") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'EXTEN' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'Peerstring' is '"SIP/+492018533416@trunk_101334_essen"' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Gosub' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@routing_intern:5] Gosub("SIP/opennumbers_equada2-000e0185", "gosub-do_mapping,00492018533416,1("SIP/+492018533416@trunk_101334_essen",3,0049,,00492018533400,2647,0,2350,12)") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG1' to '"SIP/+492018533416@trunk_101334_essen"' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG2' to '3' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG3' to '0049' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG4' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG5' to '00492018533400' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG6' to '2647' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG7' to '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG8' to '2350' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG9' to '12' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Gosub' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:1] Gosub("SIP/opennumbers_equada2-000e0185", "gosub-get_dial_args,s,1()") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG1' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG2' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG3' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG4' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG5' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG6' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG7' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG8' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG9' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'BILLING_MAXDAUER' is NULL [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-get_dial_args:1] GotoIf("SIP/opennumbers_equada2-000e0185", "1?SetArgs:") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-get_dial_args,s,3) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-get_dial_args:3] Set("SIP/opennumbers_equada2-000e0185", "DIAL_ARGS=") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Goto' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-get_dial_args:4] Goto("SIP/opennumbers_equada2-000e0185", "CheckCID") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-get_dial_args,s,6) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-get_dial_args:6] Set("SIP/opennumbers_equada2-000e0185", "CID_ANONYMOUS=0") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'DIAL_CID' is 'show' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-get_dial_args:7] GotoIf("SIP/opennumbers_equada2-000e0185", "0?:CheckCID2") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-get_dial_args,s,9) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'DIAL_CID' is 'show' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-get_dial_args:9] GotoIf("SIP/opennumbers_equada2-000e0185", "0?CleanDiversion:") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'DIAL_CID' is 'show' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-get_dial_args:10] GotoIf("SIP/opennumbers_equada2-000e0185", "0?:CleanDiversion") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-get_dial_args,s,13) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function SIP_HEADER(Diversion) result is '(null)' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function LEN() result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-get_dial_args:13] GotoIf("SIP/opennumbers_equada2-000e0185", "0?:SetUserfield") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-get_dial_args,s,18) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function CALLERID(rdnis) result is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function CDR(userfield) result is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-get_dial_args:18] Set("SIP/opennumbers_equada2-000e0185", "CDR(userfield)=D()") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-get_dial_args:19] NoOp("SIP/opennumbers_equada2-000e0185", "dial_args macro ende") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Return' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-get_dial_args:20] Return("SIP/opennumbers_equada2-000e0185", "") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:2] Set("SIP/opennumbers_equada2-000e0185", "CDR(EinkaufTelefonieProviderID)=0") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:3] Set("SIP/opennumbers_equada2-000e0185", "CHANNEL(amaflags)=omit") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function CALLERID(number) result is '00420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:4] Set("SIP/opennumbers_equada2-000e0185", "InboundNumber=00420595626958") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '3' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:5] GotoIf("SIP/opennumbers_equada2-000e0185", "1?:NoSignaling") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'InboundNumber' is '00420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '3' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG3' is '0049' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG4' is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Gosub' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:6] Gosub("SIP/opennumbers_equada2-000e0185", "gosub-convert_number,s,1(00420595626958,3,0049,)") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG1' to '00420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG2' to '3' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG3' to '0049' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG4' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG5' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG6' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG7' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG8' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG9' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is '00420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:1] Set("SIP/opennumbers_equada2-000e0185", "ConvNumber=00420595626958") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is '00420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '3' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG3' is '0049' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG4' is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:2] NoOp("SIP/opennumbers_equada2-000e0185", "konvertiere Nummer 00420595626958 in Format 3, Int=0049, Nat=") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ConvNumber' is '00420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:3] GotoIf("SIP/opennumbers_equada2-000e0185", "1?CheckFormat:") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-convert_number,s,6) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '3' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:6] GotoIf("SIP/opennumbers_equada2-000e0185", "0?Doppelnull:") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '3' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:7] GotoIf("SIP/opennumbers_equada2-000e0185", "0?E164:") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '3' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:8] GotoIf("SIP/opennumbers_equada2-000e0185", "1?E164plus:") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-convert_number,s,14) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ConvNumber' is '00420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:14] Set("SIP/opennumbers_equada2-000e0185", "ConvNumber=+420595626958") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ConvNumber' is '+420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:15] NoOp("SIP/opennumbers_equada2-000e0185", "Nummer nach E164+ konvertiert: +420595626958") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Return' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-convert_number:16] Return("SIP/opennumbers_equada2-000e0185", "") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ConvNumber' is '+420595626958' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:7] Set("SIP/opennumbers_equada2-000e0185", "CALLERID(number)=+420595626958") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:8] Set("SIP/opennumbers_equada2-000e0185", "CALLERID(name)=") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Goto' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:9] Goto("SIP/opennumbers_equada2-000e0185", "SetIdentVars") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-do_mapping,00492018533416,11) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG6' is '2647' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:11] Set("SIP/opennumbers_equada2-000e0185", "IDENT_VERTRAG=2647") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG7' is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:12] Set("SIP/opennumbers_equada2-000e0185", "LIMIT_VERTRAG=0") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG8' is '2350' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:13] Set("SIP/opennumbers_equada2-000e0185", "IDENT_ENDGERAET=2350") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG9' is '12' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:14] Set("SIP/opennumbers_equada2-000e0185", "LIMIT_ENDGERAET=12") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'IDENT_VERTRAG' is '2647' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:15] Set("SIP/opennumbers_equada2-000e0185", "GROUP(2647)=Vertrag_Eingehend") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'IDENT_VERTRAG' is '2647' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function GROUP_COUNT(Vertrag_Eingehend@2647) result is '2' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:16] NoOp("SIP/opennumbers_equada2-000e0185", "Anzahl eingehender Gespräche für diesen Vertrag=2") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'IDENT_VERTRAG' is '2647' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'LIMIT_VERTRAG' is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Gosub' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:17] Gosub("SIP/opennumbers_equada2-000e0185", "gosub-check_calllimits,s,1(Vertrag,2647,0)") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG1' to 'Vertrag' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG2' to '2647' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG3' to '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG4' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG5' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG6' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG7' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG8' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG9' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is 'Vertrag' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '2647' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG3' is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-check_calllimits:1] NoOp("SIP/opennumbers_equada2-000e0185", "Check Limit: Typ=Vertrag, ID=2647, Limit=0") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is 'Vertrag' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '2647' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function GROUP_COUNT(Vertrag_Ausgehend@2647) result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is 'Vertrag' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '2647' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function GROUP_COUNT(Vertrag_Eingehend@2647) result is '2' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '2' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-check_calllimits:2] Set("SIP/opennumbers_equada2-000e0185", "currcalls=2") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'currcalls' is '2' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-check_calllimits:3] NoOp("SIP/opennumbers_equada2-000e0185", "Count of current calls in this category is 2") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG3' is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-check_calllimits:4] GotoIf("SIP/opennumbers_equada2-000e0185", "0?CheckLimit:") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-check_calllimits:5] NoOp("SIP/opennumbers_equada2-000e0185", "No limit defined in this category") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Return' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-check_calllimits:6] Return("SIP/opennumbers_equada2-000e0185", "0") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'GOSUB_RETVAL' is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:18] GotoIf("SIP/opennumbers_equada2-000e0185", "0?OverLimit:") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'IDENT_ENDGERAET' is '2350' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:19] Set("SIP/opennumbers_equada2-000e0185", "GROUP(2350)=Endgeraet_Eingehend") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'IDENT_ENDGERAET' is '2350' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function GROUP_COUNT(Endgeraet_Eingehend@2350) result is '2' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:20] NoOp("SIP/opennumbers_equada2-000e0185", "Anzahl eingehender Gespräche für dieses Endgeraet=2") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'IDENT_ENDGERAET' is '2350' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'LIMIT_ENDGERAET' is '12' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Gosub' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:21] Gosub("SIP/opennumbers_equada2-000e0185", "gosub-check_calllimits,s,1(Endgeraet,2350,12)") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG1' to 'Endgeraet' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG2' to '2350' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG3' to '12' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG4' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG5' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG6' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG7' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG8' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] app_stack.c: Setting 'ARG9' to '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is 'Endgeraet' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '2350' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG3' is '12' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-check_calllimits:1] NoOp("SIP/opennumbers_equada2-000e0185", "Check Limit: Typ=Endgeraet, ID=2350, Limit=12") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is 'Endgeraet' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '2350' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function GROUP_COUNT(Endgeraet_Ausgehend@2350) result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is 'Endgeraet' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG2' is '2350' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function GROUP_COUNT(Endgeraet_Eingehend@2350) result is '2' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '2' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-check_calllimits:2] Set("SIP/opennumbers_equada2-000e0185", "currcalls=2") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'currcalls' is '2' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-check_calllimits:3] NoOp("SIP/opennumbers_equada2-000e0185", "Count of current calls in this category is 2") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG3' is '12' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-check_calllimits:4] GotoIf("SIP/opennumbers_equada2-000e0185", "1?CheckLimit:") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-check_calllimits,s,7) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'currcalls' is '2' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG3' is '12' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-check_calllimits:7] GotoIf("SIP/opennumbers_equada2-000e0185", "0?Overlimit:") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-check_calllimits:8] NoOp("SIP/opennumbers_equada2-000e0185", "Limit is not exceeded") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Return' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [s@gosub-check_calllimits:9] Return("SIP/opennumbers_equada2-000e0185", "0") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'GOSUB_RETVAL' is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:22] GotoIf("SIP/opennumbers_equada2-000e0185", "0?OverLimit:") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'DIAL_CID' is 'show' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '0' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:23] GotoIf("SIP/opennumbers_equada2-000e0185", "0?:CheckCDUncond") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-do_mapping,00492018533416,27) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'EXTEN' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] db.c: Unable to find key 'CD_direct' in family '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] func_db.c: DB: 00492018533416/CD_direct not found in database. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function DB(00492018533416/CD_direct) result is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:27] Set("SIP/opennumbers_equada2-000e0185", "CD_direct=") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'CD_direct' is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:28] GotoIf("SIP/opennumbers_equada2-000e0185", "1?:DoCallDirect") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG5' is '00492018533400' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] db.c: Unable to find key 'CD_direct' in family '00492018533400' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] func_db.c: DB: 00492018533400/CD_direct not found in database. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function DB(00492018533400/CD_direct) result is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:29] Set("SIP/opennumbers_equada2-000e0185", "CD_direct=") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'CD_direct' is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:30] GotoIf("SIP/opennumbers_equada2-000e0185", "1?:DoCallDirect") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:31] Set("SIP/opennumbers_equada2-000e0185", "CallTimeout=180") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'EXTEN' is '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] db.c: Unable to find key 'CD_noanswer' in family '00492018533416' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] func_db.c: DB: 00492018533416/CD_noanswer not found in database. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function DB(00492018533416/CD_noanswer) result is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:32] Set("SIP/opennumbers_equada2-000e0185", "CD_direct=") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'CD_direct' is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:33] GotoIf("SIP/opennumbers_equada2-000e0185", "1?:PrepNoanswerTimeout") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_builtins.c: Not taking any branch [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG5' is '00492018533400' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] db.c: Unable to find key 'CD_noanswer' in family '00492018533400' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] func_db.c: DB: 00492018533400/CD_noanswer not found in database. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Function DB(00492018533400/CD_noanswer) result is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:34] Set("SIP/opennumbers_equada2-000e0185", "CD_direct=") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'CD_direct' is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Expression result is '1' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'GotoIf' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:35] GotoIf("SIP/opennumbers_equada2-000e0185", "1?AccountDial:PrepNoanswerTimeout") in new stack [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx_builtins.c: Goto (gosub-do_mapping,00492018533416,41) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG5' is '00492018533400' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:41] Set("SIP/opennumbers_equada2-000e0185", "_CalleeAccountcode=00492018533400") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'ARG1' is '"SIP/+492018533416@trunk_101334_essen"' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'CallTimeout' is '180' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'DIAL_ARGS' is '' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] pbx.c: Launching 'Dial' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] pbx.c: Executing [00492018533416@gosub-do_mapping:42] Dial("SIP/opennumbers_equada2-000e0185", ""SIP/+492018533416@trunk_101334_essen",180,") in new stack [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Asked to create a SIP channel with formats: (alaw) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Allocating new SIP dialog for 5de3a86c579b208130a21ff91bac6128@93.159.248.39:5060 - INVITE (No RTP) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x2188130' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: Allocated port 14974 for RTP instance '0x2188130' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: Creating ICE session [::]:14974 (14974) for RTP instance '0x2188130' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting '10.33.0.1' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host '10.33.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting '93.159.248.39' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host '93.159.248.39' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting '93.159.248.43' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host '93.159.248.43' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting '10.2.0.1' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host '10.2.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting '10.8.0.1' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host '10.8.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting '10.50.0.1' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host '10.50.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting '10.12.0.1' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host '10.12.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting '10.16.0.1' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host '10.16.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting '10.55.0.1' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host '10.55.0.1' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting '10.0.1.1' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host '10.0.1.1' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting '2a00:fe0:1:23::100' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host '2a00:fe0:1:23::100' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting '2a00:fe0:1:23:5054:ff:fe00:13b' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host '2a00:fe0:1:23:5054:ff:fe00:13b' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:13b' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:13b' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:13c' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:13c' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:13d' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:13d' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:13e' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:13e' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:13f' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:13f' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:140' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:140' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:141' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:141' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting 'fe80::5054:ff:fe00:142' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host 'fe80::5054:ff:fe00:142' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] rtp_engine.c: RTP instance '0x2188130' is setup and ready to go [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting 'sip.relaix.net' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host 'sip.relaix.net' and port ''. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x2188130' [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] netsock2.c: Using SIP RTP TOS bits 184 [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] netsock2.c: Using SIP RTP TOS bits 184 in TCLASS field. [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] netsock2.c: Using SIP RTP CoS mark 5 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Setting NAT on RTP to Off [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] acl.c: For destination '93.159.249.131', our source address is '93.159.248.39'. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Setting AST_TRANSPORT_UDP with address 93.159.248.39:5060 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: Splitting '93.159.249.131:65002' into... [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] netsock2.c: ...host '93.159.249.131' and port '65002'. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Setting NAT on RTP to Off [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: SIP call-id changed from '5de3a86c579b208130a21ff91bac6128@93.159.248.39:5060' to '071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] stasis.c: Creating topic. name: channel:1597737087.1466172, detail: [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] stasis.c: Topic 'channel:1597737087.1466172': 0x29ff790 created [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] stasis.c: Creating topic. name: cache:1769367/channel:1597737087.1466172, detail: [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] stasis.c: Topic 'cache:1769367/channel:1597737087.1466172': 0x192d260 created [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] channel.c: Channel 0x2a01360 'SIP/trunk_101334_essen-000e0186' allocated [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: *** Our native formats are (alaw) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: *** Joint capabilities are (alaw) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: *** Our capabilities are (g722|alaw) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: *** Our preferred formats from the incoming channel are (alaw) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: This channel will not be able to handle video. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] channel_internal_api.c: Channel Call ID changing from [C-0010784a] to [C-0010784a] [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] channel.c: Inheriting variable CalleeAccountcode from SIP/opennumbers_equada2-000e0185 to SIP/trunk_101334_essen-000e0186. [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Outgoing Call for +492018533416 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Updating call counter for outgoing call [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: ** Our capability: (alaw|g722) Video flag: False Text flag: False [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: ** Our prefcodec: (alaw) [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] chan_sip.c: Audio is at 14974 [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] chan_sip.c: Adding codec alaw to SDP [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] chan_sip.c: Adding codec g722 to SDP [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: -- Done with adding codecs to SDP [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Done building SDP. Settling with this capability: (alaw|g722) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Initializing initreq for method INVITE - callid 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 0 [ 47]: INVITE sip:+492018533416@93.159.249.131 SIP/2.0 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 93.159.248.39:5060;branch=z9hG4bK59ac5dd5 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 3 [ 54]: From: ;tag=as2c355dd7 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 4 [ 38]: To: [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 5 [ 47]: Contact: [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 6 [ 60]: Call-ID: 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 8 [ 32]: User-Agent: Asterisk PBX 16.12.0 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2020 07:51:27 GMT [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 12 [102]: Remote-Party-ID: "+420595626958" ;party=calling;privacy=off;screen=no [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Header 13 [ 29]: Content-Type: application/sdp [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] chan_sip.c: Reliably Transmitting (no NAT) to 93.159.249.131:65002: [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #1903 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 93.159.249.131:65002 [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] app_dial.c: Called SIP/+492018533416@trunk_101334_essen [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] channel.c: Channel SIP/trunk_101334_essen-000e0186 setting read format path: alaw -> alaw [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] channel.c: Channel SIP/opennumbers_equada2-000e0185 setting write format path: alaw -> alaw [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] channel.c: Channel SIP/opennumbers_equada2-000e0185 setting read format path: alaw -> alaw [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] channel.c: Channel SIP/trunk_101334_essen-000e0186 setting write format path: alaw -> alaw [2020-08-18 09:51:27] VERBOSE[28564] chan_sip.c: [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 93.159.248.39:5060;branch=z9hG4bK59ac5dd5 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 2 [ 38]: To: [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 3 [ 54]: From: ;tag=as2c355dd7 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 4 [ 60]: Call-ID: 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 6 [ 80]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, INFO, SUBSCRIBE, UPDATE [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 7 [ 55]: User-Agent: Swyx LinkMgr/12.11 (SW.Rel12.10_20200423.1) [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [2020-08-18 09:51:27] VERBOSE[28564] chan_sip.c: --- (9 headers 0 lines) --- [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: = Looking for Call ID: 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 (Checking To) --From tag as2c355dd7 --To-tag [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: *** SIP TIMER: Cancelling retransmission #1903 - INVITE (got response) [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060' Request 102: Found [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: SIP response 100 to standard invite [2020-08-18 09:51:27] VERBOSE[28564] chan_sip.c: [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 0 [ 0]: [2020-08-18 09:51:27] VERBOSE[28564] chan_sip.c: [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 0 [ 0]: [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Re-scheduled destruction of SIP call 123830901-1740819949-1183802891 [2020-08-18 09:51:27] VERBOSE[28564] chan_sip.c: [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 93.159.248.39:5060;branch=z9hG4bK59ac5dd5 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 2 [ 63]: Contact: [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 3 [ 67]: To: "Begger, Simona";tag=2e5da039 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 4 [ 54]: From: ;tag=as2c355dd7 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 5 [ 60]: Call-ID: 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 7 [ 80]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, INFO, SUBSCRIBE, UPDATE [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 8 [ 55]: User-Agent: Swyx LinkMgr/12.11 (SW.Rel12.10_20200423.1) [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [2020-08-18 09:51:27] VERBOSE[28564] chan_sip.c: --- (10 headers 0 lines) --- [2020-08-18 09:51:27] DEBUG[28564] chan_sip.c: = Looking for Call ID: 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 (Checking To) --From tag as2c355dd7 --To-tag 2e5da039 [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060' Request 102: Found [2020-08-18 09:51:27] DEBUG[28564][C-0010784a] chan_sip.c: SIP response 180 to standard invite [2020-08-18 09:51:27] VERBOSE[28564][C-0010784a] sip/route.c: sip_route_dump: route/path hop: [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] app_dial.c: SIP/trunk_101334_essen-000e0186 is ringing [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] rtp_engine.c: Setting early bridge SDP of 'SIP/opennumbers_equada2-000e0185' with that of 'SIP/trunk_101334_essen-000e0186' [2020-08-18 09:51:27] DEBUG[28530] devicestate.c: No provider found, checking channel drivers for SIP - trunk_101334_essen [2020-08-18 09:51:27] DEBUG[28530] chan_sip.c: Checking device state for peer trunk_101334_essen [2020-08-18 09:51:27] DEBUG[28530] devicestate.c: Changing state for SIP/trunk_101334_essen - state 1 (Not in use) [2020-08-18 09:51:27] DEBUG[28530] devicestate.c: No provider found, checking channel drivers for SIP - trunk_101334_essen [2020-08-18 09:51:27] DEBUG[28530] chan_sip.c: Checking device state for peer trunk_101334_essen [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] chan_sip.c: [2020-08-18 09:51:27] DEBUG[28530] devicestate.c: Changing state for SIP/trunk_101334_essen - state 1 (Not in use) [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 46.182.254.135:5060 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] channel.c: Driver for channel 'SIP/opennumbers_equada2-000e0185' does not support indication 3, emulating it [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] channel.c: Channel SIP/opennumbers_equada2-000e0185 setting write format path: slin -> alaw [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] channel.c: Prodding channel 'SIP/opennumbers_equada2-000e0185' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: Setting the marker bit due to a source update [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: ast_rtp_activate (0x7faefba63b60) - setup and perform DTLS' [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: dtls_perform_handshake (0x7faefba63b60) - ssl = (nil), setup = 0 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: dtls_perform_handshake (0x7faefba63b60) - ssl = (nil), setup = 0 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: ** Our capability: (alaw) Video flag: True Text flag: True [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: ** Our prefcodec: (nothing) [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] chan_sip.c: Audio is at 19578 [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] chan_sip.c: Adding codec alaw to SDP [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: -- Done with adding codecs to SDP [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Setting framing on incoming call: 20 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Done building SDP. Settling with this capability: (alaw) [2020-08-18 09:51:27] VERBOSE[3468][C-0010784a] chan_sip.c: [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] chan_sip.c: Trying to put 'SIP/2.0 183' onto UDP socket destined for 46.182.254.135:5060 [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: Received frame with no data for RTP instance '0x7faefb4ea910' so dropping frame [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: Ooh, format changed from none to alaw [2020-08-18 09:51:27] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x7faefb4ea910' [2020-08-18 09:51:32] VERBOSE[28564] chan_sip.c: [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 93.159.248.39:5060;branch=z9hG4bK59ac5dd5 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 2 [ 63]: Contact: [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 3 [ 67]: To: "Begger, Simona";tag=2e5da039 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 4 [ 54]: From: ;tag=as2c355dd7 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 5 [ 60]: Call-ID: 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 7 [ 80]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, INFO, SUBSCRIBE, UPDATE [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 8 [ 29]: Content-Type: application/sdp [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 9 [ 55]: User-Agent: Swyx LinkMgr/12.11 (SW.Rel12.10_20200423.1) [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 10 [ 19]: Content-Length: 208 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 11 [ 0]: [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Body 0 [ 3]: v=0 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Body 1 [ 38]: o=- 3276403793 1 IN IP4 93.159.249.131 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Body 2 [ 14]: s=Swyx LinkMgr [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Body 3 [ 23]: c=IN IP4 93.159.249.131 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Body 4 [ 5]: t=0 0 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Body 5 [ 27]: m=audio 55726 RTP/AVP 8 101 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-15 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Body 9 [ 10]: a=ptime:20 [2020-08-18 09:51:32] VERBOSE[28564] chan_sip.c: --- (11 headers 10 lines) --- [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: = Looking for Call ID: 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 (Checking To) --From tag as2c355dd7 --To-tag 2e5da039 [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Acked pending invite 102 [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Stopping retransmission on '071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060' of Request 102: Match Found [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: SIP response 200 to standard invite [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [2020-08-18 09:51:32] VERBOSE[28564][C-0010784a] chan_sip.c: Got SDP version 1 and unique parts [- 3276403793 IN IP4 93.159.249.131] [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Processing session-level SDP o=- 3276403793 1 IN IP4 93.159.249.131... OK. [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Processing session-level SDP s=Swyx LinkMgr... UNSUPPORTED OR FAILED. [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] netsock2.c: Splitting '93.159.249.131' into... [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] netsock2.c: ...host '93.159.249.131' and port ''. [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Processing session-level SDP c=IN IP4 93.159.249.131... OK. [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [2020-08-18 09:51:32] VERBOSE[28564][C-0010784a] chan_sip.c: Found RTP audio format 8 [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7faf3ad88350 [2020-08-18 09:51:32] VERBOSE[28564][C-0010784a] chan_sip.c: Found RTP audio format 101 [2020-08-18 09:51:32] VERBOSE[28564][C-0010784a] chan_sip.c: Found audio description format PCMA for ID 8 [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [2020-08-18 09:51:32] VERBOSE[28564][C-0010784a] chan_sip.c: Found audio description format telephone-event for ID 101 [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [2020-08-18 09:51:32] VERBOSE[28564][C-0010784a] chan_sip.c: Capabilities: us - (g722|alaw), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw) [2020-08-18 09:51:32] VERBOSE[28564][C-0010784a] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] res_rtp_asterisk.c: Set role to CONTROLLING (0x2188130) [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] res_rtp_asterisk.c: Set role failed; no ice instance (0x2188130) [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] acl.c: For destination '93.159.249.131', our source address is '93.159.248.39'. [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x2188130' [2020-08-18 09:51:32] VERBOSE[28564][C-0010784a] chan_sip.c: Peer audio RTP is at port 93.159.249.131:55726 [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] rtp_engine.c: Copying tx payload mapping 8 (0x7faefc256f38) from 0x7faf3ad88350 to 0x2188308 [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] rtp_engine.c: Copying tx payload mapping 101 (0x7faefba7e7a8) from 0x7faf3ad88350 to 0x2188308 [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x2188130' [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: We're settling with these formats: (alaw) [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: We have an owner, now see if we need to change this call [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Setting native formats after processing SDP. peer joint formats (alaw), old nativeformats (alaw) [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] channel.c: Channel SIP/trunk_101334_essen-000e0186 setting read format path: alaw -> alaw [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] channel.c: Channel SIP/trunk_101334_essen-000e0186 setting write format path: alaw -> alaw [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] res_rtp_asterisk.c: ast_rtp_activate (0x23d4630) - setup and perform DTLS' [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] res_rtp_asterisk.c: dtls_perform_handshake (0x23d4630) - ssl = (nil), setup = 0 [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] res_rtp_asterisk.c: dtls_perform_handshake (0x23d4630) - ssl = (nil), setup = 0 [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Updating call counter for outgoing call [2020-08-18 09:51:32] VERBOSE[28564][C-0010784a] sip/route.c: sip_route_dump: route/path hop: [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] netsock2.c: Splitting '93.159.249.131:65002' into... [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] netsock2.c: ...host '93.159.249.131' and port '65002'. [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Strict routing enforced for session 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 [2020-08-18 09:51:32] VERBOSE[28564][C-0010784a] chan_sip.c: set_destination: Parsing for address/port to send to [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] netsock2.c: Splitting '93.159.249.131:65002' into... [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] netsock2.c: ...host '93.159.249.131' and port '65002'. [2020-08-18 09:51:32] VERBOSE[28564][C-0010784a] chan_sip.c: set_destination: set destination to 93.159.249.131:65002 [2020-08-18 09:51:32] VERBOSE[28564][C-0010784a] chan_sip.c: Transmitting (no NAT) to 93.159.249.131:65002: [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Trying to put 'ACK sip:+49' onto UDP socket destined for 93.159.249.131:65002 [2020-08-18 09:51:32] VERBOSE[3468][C-0010784a] app_dial.c: SIP/trunk_101334_essen-000e0186 answered SIP/opennumbers_equada2-000e0185 [2020-08-18 09:51:32] DEBUG[28530] devicestate.c: No provider found, checking channel drivers for SIP - trunk_101334_essen [2020-08-18 09:51:32] DEBUG[28530] chan_sip.c: Checking device state for peer trunk_101334_essen [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] rtp_engine.c: Setting early bridge SDP of 'SIP/opennumbers_equada2-000e0185' with that of 'SIP/trunk_101334_essen-000e0186' [2020-08-18 09:51:32] DEBUG[28530] devicestate.c: Changing state for SIP/trunk_101334_essen - state 1 (Not in use) [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] channel.c: Channel SIP/opennumbers_equada2-000e0185 setting write format path: alaw -> alaw [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] channel.c: Channel SIP/trunk_101334_essen-000e0186 setting read format path: alaw -> alaw [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] channel.c: Channel SIP/opennumbers_equada2-000e0185 setting write format path: alaw -> alaw [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] channel.c: Channel SIP/opennumbers_equada2-000e0185 setting read format path: alaw -> alaw [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] channel.c: Channel SIP/trunk_101334_essen-000e0186 setting write format path: alaw -> alaw [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] chan_sip.c: SIP answering channel: SIP/opennumbers_equada2-000e0185 [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: Setting the marker bit due to a source update [2020-08-18 09:51:32] DEBUG[28530] devicestate.c: No provider found, checking channel drivers for SIP - opennumbers_equada2 [2020-08-18 09:51:32] DEBUG[28530] chan_sip.c: Checking device state for peer opennumbers_equada2 [2020-08-18 09:51:32] DEBUG[28530] devicestate.c: Changing state for SIP/opennumbers_equada2 - state 1 (Not in use) [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: ast_rtp_activate (0x7faefba63b60) - setup and perform DTLS' [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: dtls_perform_handshake (0x7faefba63b60) - ssl = (nil), setup = 0 [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: dtls_perform_handshake (0x7faefba63b60) - ssl = (nil), setup = 0 [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] chan_sip.c: ** Our capability: (alaw) Video flag: True Text flag: True [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] chan_sip.c: ** Our prefcodec: (nothing) [2020-08-18 09:51:32] VERBOSE[3468][C-0010784a] chan_sip.c: Audio is at 19578 [2020-08-18 09:51:32] VERBOSE[3468][C-0010784a] chan_sip.c: Adding codec alaw to SDP [2020-08-18 09:51:32] VERBOSE[3468][C-0010784a] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] chan_sip.c: -- Done with adding codecs to SDP [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] chan_sip.c: Setting framing on incoming call: 20 [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] chan_sip.c: Done building SDP. Settling with this capability: (alaw) [2020-08-18 09:51:32] VERBOSE[3468][C-0010784a] chan_sip.c: [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #3003 [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 46.182.254.135:5060 [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] stasis.c: Creating topic. name: bridge:cd9de53e-f92b-4545-92b4-17d331211a31, detail: [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] stasis.c: Topic 'bridge:cd9de53e-f92b-4545-92b4-17d331211a31': 0x22af850 created [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] stasis.c: Creating topic. name: cache:1769383/bridge:cd9de53e-f92b-4545-92b4-17d331211a31, detail: [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] stasis.c: Topic 'cache:1769383/bridge:cd9de53e-f92b-4545-92b4-17d331211a31': 0x260c090 created [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31' can not use native RTP bridge as two channels are required [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Chose bridge technology simple_bridge [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: calling simple_bridge technology constructor [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: calling simple_bridge technology start [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Session timer started: 2765 - 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 900000ms [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge_channel.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: 0x1ff0d20(SIP/trunk_101334_essen-000e0186) is joining [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge_channel.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: pushing 0x1ff0d20(SIP/trunk_101334_essen-000e0186) [2020-08-18 09:51:32] VERBOSE[3491][C-0010784a] bridge_channel.c: Channel SIP/trunk_101334_essen-000e0186 joined 'simple_bridge' basic-bridge [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31' can not use native RTP bridge as two channels are required [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge.c: Bridge technology softmix does not have any capabilities we want. [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge.c: Chose bridge technology simple_bridge [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31 is already using the new technology. [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: 0x1ff0d20(SIP/trunk_101334_essen-000e0186) is joining simple_bridge technology [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] res_rtp_asterisk.c: Changing ssrc from 1228374121 to 418889494 due to a source change [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_channel.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: 0x1b711f0(SIP/opennumbers_equada2-000e0185) is joining [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_channel.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: pushing 0x1b711f0(SIP/opennumbers_equada2-000e0185) [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_channel.c: Setting channel SIP/opennumbers_equada2-000e0185 peeraccount with channel SIP/trunk_101334_essen-000e0186 accountcode '00492018533400'. [2020-08-18 09:51:32] VERBOSE[3468][C-0010784a] bridge_channel.c: Channel SIP/opennumbers_equada2-000e0185 joined 'simple_bridge' basic-bridge [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31'. Checking compatability for channels 'SIP/trunk_101334_essen-000e0186' and 'SIP/opennumbers_equada2-000e0185' [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Symmetric ptimes on the two call legs (20). May be able to native bridge in RTP [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31': Packetization comparison success between RTP streams (read_ptime0:20 == write_ptime1:20 and read_ptime1:20 == write_ptime0:20). [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge technology softmix does not have any capabilities we want. [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Chose bridge technology native_rtp [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: calling native_rtp technology constructor [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: moving 0x1ff0d20(SIP/trunk_101334_essen-000e0186) to dummy bridge temporarily [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: 0x1ff0d20(SIP/trunk_101334_essen-000e0186) is leaving simple_bridge technology (dummy) [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: calling simple_bridge technology stop [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: 0x1b711f0(SIP/opennumbers_equada2-000e0185) is joining native_rtp technology [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31'. Channel 'SIP/opennumbers_equada2-000e0185' is joining bridge tech [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31'. Attaching hook data 0x255ade0 to 'SIP/opennumbers_equada2-000e0185' [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: 0x1ff0d20(SIP/trunk_101334_essen-000e0186) is joining native_rtp technology [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31'. Channel 'SIP/trunk_101334_essen-000e0186' is joining bridge tech [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31'. Attaching hook data 0x23038e0 to 'SIP/trunk_101334_essen-000e0186' [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31'. Tech starting 'SIP/opennumbers_equada2-000e0185' and 'SIP/trunk_101334_essen-000e0186' with target 'none' [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: calling native_rtp technology start [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: calling simple_bridge technology destructor [2020-08-18 09:51:32] DEBUG[28538] cdr.c: Finalized CDR for SIP/trunk_101334_essen-000e0186 - start 1597737087.681817 answer 1597737092.201943 end 1597737092.202735 dur 4.520 bill 0.000 dispo ANSWERED [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] res_rtp_asterisk.c: Changing ssrc from 1106463277 to 440709343 due to a source change [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31'. Checking compatability for channels 'SIP/opennumbers_equada2-000e0185' and 'SIP/trunk_101334_essen-000e0186' [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge_native_rtp.c: Symmetric ptimes on the two call legs (20). May be able to native bridge in RTP [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31': Packetization comparison success between RTP streams (read_ptime0:20 == write_ptime1:20 and read_ptime1:20 == write_ptime0:20). [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge.c: Bridge technology softmix does not have any capabilities we want. [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge.c: Chose bridge technology native_rtp [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31 is already using the new technology. [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31'. Checking compatability for channels 'SIP/opennumbers_equada2-000e0185' and 'SIP/trunk_101334_essen-000e0186' [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Symmetric ptimes on the two call legs (20). May be able to native bridge in RTP [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31': Packetization comparison success between RTP streams (read_ptime0:20 == write_ptime1:20 and read_ptime1:20 == write_ptime0:20). [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge technology softmix does not have any capabilities we want. [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Chose bridge technology native_rtp [2020-08-18 09:51:32] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31 is already using the new technology. [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Auto destroying SIP dialog '7ad9d31769185f01ae000050563f00a6' [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Destroying SIP dialog 7ad9d31769185f01ae000050563f00a6 [2020-08-18 09:51:32] VERBOSE[28564] chan_sip.c: Really destroying SIP dialog '7ad9d31769185f01ae000050563f00a6' Method: REGISTER [2020-08-18 09:51:32] VERBOSE[28564] chan_sip.c: [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 0 [ 48]: ACK sip:+492018533416@93.159.248.39:5060 SIP/2.0 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 1 [ 79]: Via: SIP/2.0/UDP 46.182.254.135:5060;branch=z9hG4bK00E0F515158AAFB00E348052395C [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 2 [137]: From: "+420595626958" ;tag=0UUHS0000030000E1D0101Cu047PC2D06J9VQV [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 3 [104]: To: "+492018533416" ;tag=as475c00a8 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 4 [ 59]: Call-ID: 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 5 [ 15]: CSeq: 45177 ACK [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 6 [115]: Contact: [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [2020-08-18 09:51:32] VERBOSE[28564] chan_sip.c: --- (9 headers 0 lines) --- [2020-08-18 09:51:32] DEBUG[28564] chan_sip.c: = Looking for Call ID: 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 (Checking From) --From tag 0UUHS0000030000E1D0101Cu047PC2D06J9VQV --To-tag as475c00a8 [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #3003 [2020-08-18 09:51:32] DEBUG[28564][C-0010784a] chan_sip.c: Stopping retransmission on '8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01' of Response 45177: Match Found [2020-08-18 09:51:32] DEBUG[3491][C-0010784a] res_rtp_asterisk.c: Feeding packet with duplicate timestamp to core [2020-08-18 09:51:37] DEBUG[28538] stasis.c: Destroying topic. name: cache:1769394/channel:1597737097.1466196, detail: [2020-08-18 09:51:37] DEBUG[28538] stasis.c: Topic 'cache:1769394/channel:1597737097.1466196': 0x7faf300d5330 destroyed [2020-08-18 09:51:37] DEBUG[28538] stasis.c: Destroying topic. name: channel:1597737097.1466196, detail: [2020-08-18 09:51:37] DEBUG[28538] stasis.c: Topic 'channel:1597737097.1466196': 0x7faf301a37a0 destroyed [2020-08-18 09:51:37] DEBUG[3491][C-0010784a] res_rtp_asterisk.c: Got RTCP report of 52 bytes from 93.159.249.131:55727 [2020-08-18 09:51:38] VERBOSE[28564] chan_sip.c: [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 0 [ 48]: BYE sip:+492018533416@93.159.248.39:5060 SIP/2.0 [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 1 [ 79]: Via: SIP/2.0/UDP 46.182.254.135:5060;branch=z9hG4bK00E0F515158AAFB010C11BC8FE0A [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 2 [137]: From: "+420595626958" ;tag=0UUHS0000030000E1D0101Cu047PC2D06J9VQV [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 3 [104]: To: "+492018533416" ;tag=as475c00a8 [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 4 [ 59]: Call-ID: 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 5 [ 15]: CSeq: 45178 BYE [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 6 [115]: Contact: [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 8 [ 50]: Reason: Q.850;cause=16;text="Normal call clearing" [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [2020-08-18 09:51:38] VERBOSE[28564] chan_sip.c: --- (10 headers 0 lines) --- [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: = Looking for Call ID: 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 (Checking From) --From tag 0UUHS0000030000E1D0101Cu047PC2D06J9VQV --To-tag as475c00a8 [2020-08-18 09:51:38] DEBUG[28564][C-0010784a] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [2020-08-18 09:51:38] DEBUG[28564][C-0010784a] chan_sip.c: Initializing initreq for method BYE - callid 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 [2020-08-18 09:51:38] DEBUG[28564][C-0010784a] netsock2.c: Splitting '46.182.254.135:5060' into... [2020-08-18 09:51:38] DEBUG[28564][C-0010784a] netsock2.c: ...host '46.182.254.135' and port '5060'. [2020-08-18 09:51:38] VERBOSE[28564][C-0010784a] chan_sip.c: Sending to 46.182.254.135:5060 (no NAT) [2020-08-18 09:51:38] DEBUG[28564][C-0010784a] chan_sip.c: Setting SIP_ALREADYGONE on dialog 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 [2020-08-18 09:51:38] VERBOSE[28564][C-0010784a] chan_sip.c: Scheduling destruction of SIP dialog '8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01' in 6400 ms (Method: BYE) [2020-08-18 09:51:38] DEBUG[28564][C-0010784a] chan_sip.c: Received bye, issuing owner hangup [2020-08-18 09:51:38] VERBOSE[28564][C-0010784a] chan_sip.c: [2020-08-18 09:51:38] DEBUG[28564][C-0010784a] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 46.182.254.135:5060 [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Session timer stopped: 2765 - 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] bridge_channel.c: Setting 0x1b711f0(SIP/opennumbers_equada2-000e0185) state from:0 to:1 [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] bridge_channel.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: pulling 0x1b711f0(SIP/opennumbers_equada2-000e0185) [2020-08-18 09:51:38] VERBOSE[3468][C-0010784a] bridge_channel.c: Channel SIP/opennumbers_equada2-000e0185 left 'native_rtp' basic-bridge [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] bridge_channel.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: 0x1b711f0(SIP/opennumbers_equada2-000e0185) is leaving native_rtp technology [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31'. Channel 'SIP/opennumbers_equada2-000e0185' is leaving bridge tech [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31'. Detaching hook data 0x1ac6398 from 'SIP/opennumbers_equada2-000e0185' [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31'. Tech stopping 'SIP/opennumbers_equada2-000e0185' and 'SIP/trunk_101334_essen-000e0186' with target 'none' [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Discontinued RTP bridging of 'SIP/opennumbers_equada2-000e0185' and 'SIP/trunk_101334_essen-000e0186' - media will flow through Asterisk core [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] bridge_native_rtp.c: Destroying channel tech_pvt data 0x255ade0 [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: dissolving bridge with cause 16(Normal Clearing) [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] bridge_channel.c: Setting 0x1ff0d20(SIP/trunk_101334_essen-000e0186) state from:0 to:2 [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: queueing action type:13 sub:1001 [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31 is dissolved, not performing smart bridge operation. [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] bridge_channel.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: pulling 0x1ff0d20(SIP/trunk_101334_essen-000e0186) [2020-08-18 09:51:38] VERBOSE[3491][C-0010784a] bridge_channel.c: Channel SIP/trunk_101334_essen-000e0186 left 'native_rtp' basic-bridge [2020-08-18 09:51:38] DEBUG[28538] cdr.c: Finalized CDR for SIP/opennumbers_equada2-000e0185 - start 1597737087.673710 answer 1597737092.202224 end 1597737098.740608 dur 11.066 bill 6.538 dispo ANSWERED [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] bridge_channel.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: 0x1ff0d20(SIP/trunk_101334_essen-000e0186) is leaving native_rtp technology [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31'. Channel 'SIP/trunk_101334_essen-000e0186' is leaving bridge tech [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] bridge_native_rtp.c: Bridge 'cd9de53e-f92b-4545-92b4-17d331211a31'. Detaching hook data 0x1b3b338 from 'SIP/trunk_101334_essen-000e0186' [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] bridge_native_rtp.c: Destroying channel tech_pvt data 0x23038e0 [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] bridge_channel.c: Channel SIP/trunk_101334_essen-000e0186 will survive this bridge; clearing outgoing (dialed) flag [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31 is dissolved, not performing smart bridge operation. [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] res_rtp_asterisk.c: Changing ssrc from 1106369796 to 581625507 due to a source change [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: actually destroying basic bridge, nobody wants it anymore [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: calling basic bridge destructor [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] app_dial.c: Exiting with DIALSTATUS=ANSWER. [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] pbx.c: Spawn extension (gosub-do_mapping,00492018533416,42) exited non-zero on 'SIP/opennumbers_equada2-000e0185' [2020-08-18 09:51:38] VERBOSE[3468][C-0010784a] pbx.c: Spawn extension (gosub-do_mapping, 00492018533416, 42) exited non-zero on 'SIP/opennumbers_equada2-000e0185' [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] channel.c: Soft-Hanging (0x10) up channel 'SIP/opennumbers_equada2-000e0185' [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] channel.c: Soft-Hanging (0x80) up channel 'SIP/opennumbers_equada2-000e0185' [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'HANGUPCAUSE' is '16' [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: calling native_rtp technology stop [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] bridge.c: Bridge cd9de53e-f92b-4545-92b4-17d331211a31: calling native_rtp technology destructor [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] stasis.c: Destroying topic. name: cache:1769383/bridge:cd9de53e-f92b-4545-92b4-17d331211a31, detail: [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] stasis.c: Topic 'cache:1769383/bridge:cd9de53e-f92b-4545-92b4-17d331211a31': 0x260c090 destroyed [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] stasis.c: Destroying topic. name: bridge:cd9de53e-f92b-4545-92b4-17d331211a31, detail: [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] stasis.c: Topic 'bridge:cd9de53e-f92b-4545-92b4-17d331211a31': 0x22af850 destroyed [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] channel.c: Channel 0x2a01360 'SIP/trunk_101334_essen-000e0186' hanging up. Refs: 2 [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] chan_sip.c: Hangup call SIP/trunk_101334_essen-000e0186, SIP callid 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 [2020-08-18 09:51:38] VERBOSE[3491][C-0010784a] chan_sip.c: Scheduling destruction of SIP dialog '071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060' in 32000 ms (Method: INVITE) [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] pbx_variables.c: Function CDR(userfield) result is 'D()' [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] pbx.c: Launching 'Set' [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] chan_sip.c: Strict routing enforced for session 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 [2020-08-18 09:51:38] VERBOSE[3468][C-0010784a] pbx.c: Executing [h@gosub-do_mapping:1] Set("SIP/opennumbers_equada2-000e0185", "CDR(userfield)=H(16)D()") in new stack [2020-08-18 09:51:38] VERBOSE[3491][C-0010784a] chan_sip.c: set_destination: Parsing for address/port to send to [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] netsock2.c: Splitting '93.159.249.131:65002' into... [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] netsock2.c: ...host '93.159.249.131' and port '65002'. [2020-08-18 09:51:38] VERBOSE[3491][C-0010784a] chan_sip.c: set_destination: set destination to 93.159.249.131:65002 [2020-08-18 09:51:38] VERBOSE[3491][C-0010784a] chan_sip.c: Reliably Transmitting (no NAT) to 93.159.249.131:65002: [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #3408 [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] chan_sip.c: Trying to put 'BYE sip:+49' onto UDP socket destined for 93.159.249.131:65002 [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] channel.c: Channel 0x2a01360 'SIP/trunk_101334_essen-000e0186' destroying [2020-08-18 09:51:38] DEBUG[28538] cdr.c: CDR for SIP/trunk_101334_essen-000e0186 is dialed and has no Party B; discarding [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'DIALSTATUS' is 'ANSWER' [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'HANGUPCAUSE' is '16' [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] pbx_variables.c: Function CHANNEL(rtpqos,audio,all) result is 'ssrc=1191057125;themssrc=1106369796;lp=0;rxjitter=0.000000;rxcount=530;txjitter=0.000108;txcount=549;rlp=0;rtt=0.000000' [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] pbx.c: Launching 'NoOp' [2020-08-18 09:51:38] VERBOSE[3468][C-0010784a] pbx.c: Executing [h@gosub-do_mapping:2] NoOp("SIP/opennumbers_equada2-000e0185", "Hangup occured (Stat=ANSWER, Cause=16, QoS=ssrc=1191057125;themssrc=1106369796;lp=0;rxjitter=0.000000;rxcount=530;txjitter=0.000108;txcount=549;rlp=0;rtt=0.000000") in new stack [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] pbx_variables.c: Result of 'HANGUPCAUSE' is '16' [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] pbx.c: Launching 'Hangup' [2020-08-18 09:51:38] VERBOSE[3468][C-0010784a] pbx.c: Executing [h@gosub-do_mapping:3] Hangup("SIP/opennumbers_equada2-000e0185", "16") in new stack [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] stasis.c: Destroying topic. name: cache:1769367/channel:1597737087.1466172, detail: [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] stasis.c: Topic 'cache:1769367/channel:1597737087.1466172': 0x192d260 destroyed [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] stasis.c: Destroying topic. name: channel:1597737087.1466172, detail: [2020-08-18 09:51:38] DEBUG[3491][C-0010784a] stasis.c: Topic 'channel:1597737087.1466172': 0x29ff790 destroyed [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] channel.c: Soft-Hanging (0x20) up channel 'SIP/opennumbers_equada2-000e0185' [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] pbx.c: Spawn extension (gosub-do_mapping,h,3) exited non-zero on 'SIP/opennumbers_equada2-000e0185' [2020-08-18 09:51:38] VERBOSE[3468][C-0010784a] pbx.c: Spawn extension (gosub-do_mapping, h, 3) exited non-zero on 'SIP/opennumbers_equada2-000e0185' [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] channel.c: Channel 0x7faefb629c50 'SIP/opennumbers_equada2-000e0185' hanging up. Refs: 2 [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] chan_sip.c: Hangup call SIP/opennumbers_equada2-000e0185, SIP callid 8415e00015f5-5f3b887f-4712862f-237c9070-39d0fe7-01 [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] channel.c: Channel 0x7faefb629c50 'SIP/opennumbers_equada2-000e0185' destroying [2020-08-18 09:51:38] DEBUG[28530] devicestate.c: No provider found, checking channel drivers for SIP - trunk_101334_essen [2020-08-18 09:51:38] DEBUG[28530] chan_sip.c: Checking device state for peer trunk_101334_essen [2020-08-18 09:51:38] DEBUG[28530] devicestate.c: Changing state for SIP/trunk_101334_essen - state 1 (Not in use) [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] stasis.c: Destroying topic. name: cache:1769366/channel:1597737087.1466171, detail: [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] stasis.c: Topic 'cache:1769366/channel:1597737087.1466171': 0x7faefab7c9a0 destroyed [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] stasis.c: Destroying topic. name: channel:1597737087.1466171, detail: [2020-08-18 09:51:38] DEBUG[3468][C-0010784a] stasis.c: Topic 'channel:1597737087.1466171': 0x7faefb446df0 destroyed [2020-08-18 09:51:38] DEBUG[28530] devicestate.c: No provider found, checking channel drivers for SIP - opennumbers_equada2 [2020-08-18 09:51:38] DEBUG[28538] cdr_mysql.c: Inserting a CDR record. [2020-08-18 09:51:38] DEBUG[28530] chan_sip.c: Checking device state for peer opennumbers_equada2 [2020-08-18 09:51:38] DEBUG[28538] cdr_mysql.c: SQL command as follows: INSERT INTO TelefonieCDR (`calldate`,`clid`,`src`,`dst`,`dcontext`,`channel`,`dstchannel`,`lastapp`,`lastdata`,`duration`,`billsec`,`disposition`,`amaflags`,`userfield`,`uniqueid`,`RxSrc`,`RxDst`,`RxOrigin`,`EinkaufTelefonieProviderID`) VALUES ('2020-08-18 09:51:27','\"\" <+420595626958>','+420595626958','00492018533416','routing_intern','SIP/opennumbers_equada2-000e0185','SIP/trunk_101334_essen-000e0186','Dial','\"SIP/+492018533416@trunk_101334_essen\",180,','11','6','ANSWERED','1','H(16)D()','1597737087.1466171','00420595626958','00492018533416','remote','0') [2020-08-18 09:51:38] DEBUG[28530] devicestate.c: Changing state for SIP/opennumbers_equada2 - state 1 (Not in use) [2020-08-18 09:51:38] DEBUG[28538] stasis.c: Creating topic. name: channel:1597737098.1466201, detail: [2020-08-18 09:51:38] DEBUG[28538] stasis.c: Topic 'channel:1597737098.1466201': 0x7faf300882b0 created [2020-08-18 09:51:38] DEBUG[28538] stasis.c: Creating topic. name: cache:1769402/channel:1597737098.1466201, detail: [2020-08-18 09:51:38] DEBUG[28538] stasis.c: Topic 'cache:1769402/channel:1597737098.1466201': 0x7faf301bcf50 created [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(accountcode)})' (from 'CSV_QUOTE(${CDR(accountcode)})},${CSV_QUOTE(${CDR(src)})},${CSV_QUOTE(${CDR(dst)})},${CSV_QUOTE(${CDR(dcontext)})},${CSV_QUOTE(${CDR(clid)})},${CSV_QUOTE(${CDR(channel)})},${CSV_QUOTE(${CDR(dstchannel)})},${CSV_QUOTE(${CDR(lastapp)})},${CSV_QUOTE(${CDR(lastdata)})},${CSV_QUOTE(${CDR(start)})},${CSV_QUOTE(${CDR(answer)})},${CSV_QUOTE(${CDR(end)})},${CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(accountcode)' (from 'CDR(accountcode)})' len 16) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(accountcode) result is '' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE() result is '""' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(src)})' (from 'CSV_QUOTE(${CDR(src)})},${CSV_QUOTE(${CDR(dst)})},${CSV_QUOTE(${CDR(dcontext)})},${CSV_QUOTE(${CDR(clid)})},${CSV_QUOTE(${CDR(channel)})},${CSV_QUOTE(${CDR(dstchannel)})},${CSV_QUOTE(${CDR(lastapp)})},${CSV_QUOTE(${CDR(lastdata)})},${CSV_QUOTE(${CDR(start)})},${CSV_QUOTE(${CDR(answer)})},${CSV_QUOTE(${CDR(end)})},${CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(src)' (from 'CDR(src)})' len 8) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(src) result is '+420595626958' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(+420595626958) result is '"+420595626958"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(dst)})' (from 'CSV_QUOTE(${CDR(dst)})},${CSV_QUOTE(${CDR(dcontext)})},${CSV_QUOTE(${CDR(clid)})},${CSV_QUOTE(${CDR(channel)})},${CSV_QUOTE(${CDR(dstchannel)})},${CSV_QUOTE(${CDR(lastapp)})},${CSV_QUOTE(${CDR(lastdata)})},${CSV_QUOTE(${CDR(start)})},${CSV_QUOTE(${CDR(answer)})},${CSV_QUOTE(${CDR(end)})},${CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(dst)' (from 'CDR(dst)})' len 8) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(dst) result is '00492018533416' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(00492018533416) result is '"00492018533416"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(dcontext)})' (from 'CSV_QUOTE(${CDR(dcontext)})},${CSV_QUOTE(${CDR(clid)})},${CSV_QUOTE(${CDR(channel)})},${CSV_QUOTE(${CDR(dstchannel)})},${CSV_QUOTE(${CDR(lastapp)})},${CSV_QUOTE(${CDR(lastdata)})},${CSV_QUOTE(${CDR(start)})},${CSV_QUOTE(${CDR(answer)})},${CSV_QUOTE(${CDR(end)})},${CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(dcontext)' (from 'CDR(dcontext)})' len 13) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(dcontext) result is 'routing_intern' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(routing_intern) result is '"routing_intern"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(clid)})' (from 'CSV_QUOTE(${CDR(clid)})},${CSV_QUOTE(${CDR(channel)})},${CSV_QUOTE(${CDR(dstchannel)})},${CSV_QUOTE(${CDR(lastapp)})},${CSV_QUOTE(${CDR(lastdata)})},${CSV_QUOTE(${CDR(start)})},${CSV_QUOTE(${CDR(answer)})},${CSV_QUOTE(${CDR(end)})},${CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(clid)' (from 'CDR(clid)})' len 9) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(clid) result is '"" <+420595626958>' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE("" <+420595626958>) result is '""""" <+420595626958>"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(channel)})' (from 'CSV_QUOTE(${CDR(channel)})},${CSV_QUOTE(${CDR(dstchannel)})},${CSV_QUOTE(${CDR(lastapp)})},${CSV_QUOTE(${CDR(lastdata)})},${CSV_QUOTE(${CDR(start)})},${CSV_QUOTE(${CDR(answer)})},${CSV_QUOTE(${CDR(end)})},${CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(channel)' (from 'CDR(channel)})' len 12) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(channel) result is 'SIP/opennumbers_equada2-000e0185' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(SIP/opennumbers_equada2-000e0185) result is '"SIP/opennumbers_equada2-000e0185"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(dstchannel)})' (from 'CSV_QUOTE(${CDR(dstchannel)})},${CSV_QUOTE(${CDR(lastapp)})},${CSV_QUOTE(${CDR(lastdata)})},${CSV_QUOTE(${CDR(start)})},${CSV_QUOTE(${CDR(answer)})},${CSV_QUOTE(${CDR(end)})},${CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(dstchannel)' (from 'CDR(dstchannel)})' len 15) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(dstchannel) result is 'SIP/trunk_101334_essen-000e0186' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(SIP/trunk_101334_essen-000e0186) result is '"SIP/trunk_101334_essen-000e0186"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(lastapp)})' (from 'CSV_QUOTE(${CDR(lastapp)})},${CSV_QUOTE(${CDR(lastdata)})},${CSV_QUOTE(${CDR(start)})},${CSV_QUOTE(${CDR(answer)})},${CSV_QUOTE(${CDR(end)})},${CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(lastapp)' (from 'CDR(lastapp)})' len 12) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(lastapp) result is 'Dial' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(Dial) result is '"Dial"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(lastdata)})' (from 'CSV_QUOTE(${CDR(lastdata)})},${CSV_QUOTE(${CDR(start)})},${CSV_QUOTE(${CDR(answer)})},${CSV_QUOTE(${CDR(end)})},${CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(lastdata)' (from 'CDR(lastdata)})' len 13) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(lastdata) result is '"SIP/+492018533416@trunk_101334_essen",180,' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE("SIP/+492018533416@trunk_101334_essen",180,) result is '"""SIP/+492018533416@trunk_101334_essen"",180,"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(start)})' (from 'CSV_QUOTE(${CDR(start)})},${CSV_QUOTE(${CDR(answer)})},${CSV_QUOTE(${CDR(end)})},${CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(start)' (from 'CDR(start)})' len 10) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(start) result is '2020-08-18 09:51:27' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(2020-08-18 09:51:27) result is '"2020-08-18 09:51:27"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(answer)})' (from 'CSV_QUOTE(${CDR(answer)})},${CSV_QUOTE(${CDR(end)})},${CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(answer)' (from 'CDR(answer)})' len 11) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(answer) result is '2020-08-18 09:51:32' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(2020-08-18 09:51:32) result is '"2020-08-18 09:51:32"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(end)})' (from 'CSV_QUOTE(${CDR(end)})},${CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(end)' (from 'CDR(end)})' len 8) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(end) result is '2020-08-18 09:51:38' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(2020-08-18 09:51:38) result is '"2020-08-18 09:51:38"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(duration)})' (from 'CSV_QUOTE(${CDR(duration)})},${CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(duration)' (from 'CDR(duration)})' len 13) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(duration) result is '11' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(11) result is '"11"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(billsec)})' (from 'CSV_QUOTE(${CDR(billsec)})},${CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(billsec)' (from 'CDR(billsec)})' len 12) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(billsec) result is '6' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(6) result is '"6"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(disposition)})' (from 'CSV_QUOTE(${CDR(disposition)})},${CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(disposition)' (from 'CDR(disposition)})' len 16) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(disposition) result is 'ANSWERED' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(ANSWERED) result is '"ANSWERED"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(amaflags)})' (from 'CSV_QUOTE(${CDR(amaflags)})},${CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(amaflags)' (from 'CDR(amaflags)})' len 13) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(amaflags) result is 'OMIT' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(OMIT) result is '"OMIT"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(uniqueid)})' (from 'CSV_QUOTE(${CDR(uniqueid)})},${CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(uniqueid)' (from 'CDR(uniqueid)})' len 13) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(uniqueid) result is '1597737087.1466171' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(1597737087.1466171) result is '"1597737087.1466171"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(userfield)})' (from 'CSV_QUOTE(${CDR(userfield)})},${CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(userfield)' (from 'CDR(userfield)})' len 14) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(userfield) result is 'H(16)D()' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(H(16)D()) result is '"H(16)D()"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(RxSrc)})' (from 'CSV_QUOTE(${CDR(RxSrc)})},${CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(RxSrc)' (from 'CDR(RxSrc)})' len 10) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(RxSrc) result is '00420595626958' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(00420595626958) result is '"00420595626958"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(RxDst)})' (from 'CSV_QUOTE(${CDR(RxDst)})},${CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(RxDst)' (from 'CDR(RxDst)})' len 10) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(RxDst) result is '00492018533416' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(00492018533416) result is '"00492018533416"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(RxNebenstelle)})' (from 'CSV_QUOTE(${CDR(RxNebenstelle)})},${CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(RxNebenstelle)' (from 'CDR(RxNebenstelle)})' len 18) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(RxNebenstelle) result is '' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE() result is '""' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(RxOrigin)})' (from 'CSV_QUOTE(${CDR(RxOrigin)})},${CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(RxOrigin)' (from 'CDR(RxOrigin)})' len 13) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(RxOrigin) result is 'remote' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(remote) result is '"remote"' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})' (from 'CSV_QUOTE(${CDR(EinkaufTelefonieProviderID)})} [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Evaluating 'CDR(EinkaufTelefonieProviderID)' (from 'CDR(EinkaufTelefonieProviderID)})' len 31) [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CDR(EinkaufTelefonieProviderID) result is '0' [2020-08-18 09:51:38] DEBUG[28538] pbx_variables.c: Function CSV_QUOTE(0) result is '"0"' [2020-08-18 09:51:38] DEBUG[28538] stasis.c: Destroying topic. name: cache:1769402/channel:1597737098.1466201, detail: [2020-08-18 09:51:38] DEBUG[28538] stasis.c: Topic 'cache:1769402/channel:1597737098.1466201': 0x7faf301bcf50 destroyed [2020-08-18 09:51:38] DEBUG[28538] stasis.c: Destroying topic. name: channel:1597737098.1466201, detail: [2020-08-18 09:51:38] DEBUG[28538] stasis.c: Topic 'channel:1597737098.1466201': 0x7faf300882b0 destroyed [2020-08-18 09:51:38] DEBUG[28538] stasis.c: Destroying topic. name: cache:1769403/channel:1597737098.1466202, detail: [2020-08-18 09:51:38] DEBUG[28538] stasis.c: Topic 'cache:1769403/channel:1597737098.1466202': 0x7faf301146c0 destroyed [2020-08-18 09:51:38] DEBUG[28538] stasis.c: Destroying topic. name: channel:1597737098.1466202, detail: [2020-08-18 09:51:38] DEBUG[28538] stasis.c: Topic 'channel:1597737098.1466202': 0x7faf300a7a70 destroyed [2020-08-18 09:51:38] VERBOSE[28564] chan_sip.c: [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 0 [ 3]: jaK [2020-08-18 09:51:38] VERBOSE[28564] chan_sip.c: [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 93.159.248.39:5060;branch=z9hG4bK4636c5c5 [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 2 [ 63]: Contact: [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 3 [ 51]: To: ;tag=2e5da039 [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 4 [ 54]: From: ;tag=as2c355dd7 [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 5 [ 60]: Call-ID: 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 6 [ 13]: CSeq: 103 BYE [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 7 [ 80]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, INFO, SUBSCRIBE, UPDATE [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 8 [ 55]: User-Agent: Swyx LinkMgr/12.11 (SW.Rel12.10_20200423.1) [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [2020-08-18 09:51:38] VERBOSE[28564] chan_sip.c: --- (10 headers 0 lines) --- [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: = Looking for Call ID: 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 (Checking To) --From tag as2c355dd7 --To-tag 2e5da039 [2020-08-18 09:51:38] DEBUG[28564][C-0010784a] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #3408 [2020-08-18 09:51:38] DEBUG[28564][C-0010784a] chan_sip.c: Stopping retransmission on '071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060' of Request 103: Match Found [2020-08-18 09:51:38] DEBUG[28564] chan_sip.c: Destroying SIP dialog 071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060 [2020-08-18 09:51:38] VERBOSE[28564] chan_sip.c: Really destroying SIP dialog '071fdc4771a691461431b1c612f39c9f@93.159.248.39:5060' Method: INVITE [2020-08-18 09:51:38] DEBUG[28564] rtp_engine.c: Destroyed RTP instance '0x2188130'