2846 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:23] Set("SIP/2002-00000002", "__CRM_SOURCE=2002") in new stack 42847 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:24] AGI("SIP/2002-00000002", "agi://127.0.0.1/sangomacrm.agi") in new stack 42848 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] res_agi.c: AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0 42849 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:25] Set("SIP/2002-00000002", "CHANNEL(hangup_handler_push)=crm-hangup,s,1") in new stack 42850 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:26] NoOp("SIP/2002-00000002", "CRM Finished") in new stack 42851 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:27] GotoIf("SIP/2002-00000002", "0?bypass,1") in new stack 42852 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:28] ExecIf("SIP/2002-00000002", "1?Set(CONNECTEDLINE(num,i)=7252818157)") in new stack 42853 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:29] ExecIf("SIP/2002-00000002", "1?Set(CONNECTEDLINE(name,i)=CID:6614101)") in new stack 42854 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:30] ExecIf("SIP/2002-00000002", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)6614101)") in new stack 42855 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:31] GotoIf("SIP/2002-00000002", "0?customtrunk") in new stack 42856 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:32] ExecIf("SIP/2002-00000002", "0?Set(DIAL_TRUNK_OPTIONS=)") in new stack 42857 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:33] Set("SIP/2002-00000002", "HASH(__SIPHEADERS,Alert-Info)=unset") in new stack 42858 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-dialout-trunk:34] Dial("SIP/2002-00000002", "SIP/tatasip/7252818157,300,Tb(func-apply-sipheaders^s^1,(1))U(sub-send-obroute-email^7252818157^7252818157^1^1613806720^^6614101)") in new stack 42859 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] netsock2.c: Using SIP RTP TOS bits 184 42860 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] netsock2.c: Using SIP RTP CoS mark 5 42861 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] app_stack.c: SIP/tatasip-00000003 Internal Gosub(func-apply-sipheaders,s,1(1)) start 42862 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("SIP/tatasip-00000003", "0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack 42863 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("SIP/tatasip-00000003", "Applying SIP Headers to channel SIP/tatasip-00000003") in new stack 42864 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:3] Set("SIP/tatasip-00000003", "TECH=SIP") in new stack 42865 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:4] Set("SIP/tatasip-00000003", "SIPHEADERKEYS=Alert-Info") in new stack 42866 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/tatasip-00000003", "1") in new stack 42867 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:6] Set("SIP/tatasip-00000003", "sipheader=unset") in new stack 42868 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:7] ExecIf("SIP/tatasip-00000003", "1?SIPRemoveHeader(Alert-Info:)") in new stack 42869 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:8] ExecIf("SIP/tatasip-00000003", "0?Set(PJSIP_HEADER(remove,Alert-Info)=)") in new stack 42870 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:9] ExecIf("SIP/tatasip-00000003", "0?Set(sipheader=;info=unset)") in new stack 42871 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:10] ExecIf("SIP/tatasip-00000003", "0?Set(sipheader=unset)") in new stack 42872 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:11] ExecIf("SIP/tatasip-00000003", "0?SIPAddHeader(Alert-Info:unset)") in new stack 42873 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:12] ExecIf("SIP/tatasip-00000003", "0?Set(PJSIP_HEADER(add,Alert-Info)=unset)") in new stack 42874 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:13] EndWhile("SIP/tatasip-00000003", "") in new stack 42875 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/tatasip-00000003", "0") in new stack 42876 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] pbx.c: Executing [s@func-apply-sipheaders:14] Return("SIP/tatasip-00000003", "") in new stack 42877 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] app_stack.c: Spawn extension (tata , 7252818157, 1) exited non-zero on 'SIP/tatasip-00000003' 42878 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] app_stack.c: SIP/tatasip-00000003 Internal Gosub(func-apply-sipheaders,s,1(1)) complete GOSUB_RETVAL= 42879 [2021-02-20 07:38:40] VERBOSE[23433][C-00000002] app_dial.c: Called SIP/tatasip/7252818157 42880 [2021-02-20 07:38:44] VERBOSE[23433][C-00000002] app_dial.c: SIP/tatasip-00000003 is making progress passing it to SIP/2002-00000002 42881 [2021-02-20 07:38:46] VERBOSE[23433][C-00000002] app_dial.c: SIP/tatasip-00000003 is ringing 42882 [2021-02-20 07:38:46] VERBOSE[23433][C-00000002] app_dial.c: SIP/tatasip-00000003 is ringing 42883 [2021-02-20 07:38:46] VERBOSE[23433][C-00000002] app_dial.c: SIP/tatasip-00000003 is ringing 42884 [2021-02-20 07:38:46] VERBOSE[23433][C-00000002] app_dial.c: SIP/tatasip-00000003 is ringing 42885 [2021-02-20 07:38:47] VERBOSE[23433][C-00000002] app_dial.c: SIP/tatasip-00000003 is ringing 42886 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] app_macro.c: Spawn extension (macro-dialout-trunk, s, 34) exited non-zero on 'SIP/2002-00000002' in macro 'dialout-trunk' 42887 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Spawn extension (from-internal, 7252818157, 11) exited non-zero on 'SIP/2002-00000002' 42888 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [h@from-internal:1] Macro("SIP/2002-00000002", "hangupcall") in new stack 42889 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("SIP/2002-00000002", "1?theend") in new stack 42890 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx_builtins.c: Goto (macro-hangupcall,s,3) 42891 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("SIP/2002-00000002", "0?Set(CDR(recordingfile)=)") in new stack 42892 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-hangupcall:4] NoOp("SIP/2002-00000002", "SIP/tatasip-00000003 montior file= ") in new stack 42893 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("SIP/2002-00000002", "1?skipagi") in new stack 42894 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx_builtins.c: Goto (macro-hangupcall,s,7) 42895 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [s@macro-hangupcall:7] Hangup("SIP/2002-00000002", "") in new stack 42896 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'SIP/2002-00000002' in macro 'hangupcall' 42897 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/2002-00000002' 42898 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] app_stack.c: SIP/2002-00000002 Internal Gosub(crm-hangup,s,1) start 42899 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [s@crm-hangup:1] NoOp("SIP/2002-00000002", "Sending Hangup to CRM") in new stack 42900 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [s@crm-hangup:2] NoOp("SIP/2002-00000002", "HANGUP CAUSE: 16") in new stack 42901 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [s@crm-hangup:3] ExecIf("SIP/2002-00000002", "0?Set(__CRM_VOICEMAIL=)") in new stack 42902 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [s@crm-hangup:4] NoOp("SIP/2002-00000002", "MASTER CHANNEL: 1613806720.2 = 1613806720.2") in new stack 42903 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [s@crm-hangup:5] GotoIf("SIP/2002-00000002", "0?return") in new stack 42904 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [s@crm-hangup:6] Set("SIP/2002-00000002", "__CRM_HANGUP=1") in new stack 42905 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [s@crm-hangup:7] AGI("SIP/2002-00000002", "agi://127.0.0.1/sangomacrm.agi") in new stack 42906 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] res_agi.c: AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0 42907 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] pbx.c: Executing [s@crm-hangup:8] Return("SIP/2002-00000002", "") in new stack 42908 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] app_stack.c: Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/2002-00000002' 42909 [2021-02-20 07:38:49] VERBOSE[23433][C-00000002] app_stack.c: SIP/2002-00000002 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL= 42910 [2021-02-20 07:39:24] VERBOSE[21530][C-00000003] netsock2.c: Using SIP RTP TOS bits 184 42911 [2021-02-20 07:39:24] VERBOSE[21530][C-00000003] netsock2.c: Using SIP RTP CoS mark 5 42912 [2021-02-20 07:39:24] NOTICE[21530][C-00000003] chan_sip.c: Call from 'tatasip' (10.50.185.2:5060) to extension '6614100' rejected because extension not found in context 'tata '. 42913 [2021-02-20 07:39:51] VERBOSE[21530][C-00000004] netsock2.c: Using SIP RTP TOS bits 184 42914 [2021-02-20 07:39:51] VERBOSE[21530][C-00000004] netsock2.c: Using SIP RTP CoS mark 5 42915 [2021-02-20 07:39:51] NOTICE[21530][C-00000004] chan_sip.c: Call from 'tatasip' (10.50.185.2:5060) to extension '6614100' rejected because extension not found in context 'tata '. 42916 [2021-02-20 07:43:59] VERBOSE[21530] chan_sip.c: 42917 <--- SIP read from UDP:10.100.148.1:51122 ---> 42918 42919 <-------------> 42920 [2021-02-20 07:44:06] VERBOSE[21530] chan_sip.c: 42921 <--- SIP read from UDP:10.50.185.2:5060 ---> 42922 INVITE sip:6614100@10.50.192.54:5060;transport=UDP SIP/2.0 42923 From: "917252818157";tag=BN1705504033-1-1613807044-386724751 42924 To: "1356614101" 42925 Call-ID: 6aa7519e-43332398-25c1b4-7fb6170b1c88-cdc0a20a-13c4-759 42926 CSeq: 22943 INVITE 42927 Via: SIP/2.0/UDP 10.50.185.2:5060;branch=z9hG4bK-53d6d23e-25c1b4-937ca7c3-7fb64025ab20 42928 Route: 42929 X-SessionId: 1705504033 42930 User-Agent: BN4000-3.8.1-912 42931 Supported: timer,100rel 42932 Max-Forwards: 68 42933 Contact: 42934 Allow: INVITE,CANCEL,ACK,BYE,OPTIONS,INFO,PRACK,UPDATE,REFER,NOTIFY,SUBSCRIBE,PUBLISH,MESSAGE,REGISTER 42935 Session-Expires: 1800 42936 Min-SE: 90 42937 Content-Type: application/sdp 42938 Content-Length: 173 42939 42940 v=0 42941 o=BN4000 468 14413 IN IP4 10.50.185.2 42942 s=- 42943 c=IN IP4 10.50.185.2 42944 t=0 0 42945 m=audio 64112 RTP/AVP 0 8 18 97 42946 a=rtpmap:97 telephone-event/8000 42947 a=fmtp:97 0-15 42948 a=ptime:20 42949 <-------------> 42950 [2021-02-20 07:44:06] VERBOSE[21530] chan_sip.c: --- (17 headers 9 lines) --- 42951 [2021-02-20 07:44:06] VERBOSE[21530] chan_sip.c: Sending to 10.50.185.2:5060 (NAT) 42952 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Sending to 10.50.185.2:5060 (NAT) 42953 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Using INVITE request as basis request - 6aa7519e-43332398-25c1b4-7fb6170b1c88-cdc0a20a-13c4-759 42954 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Found peer 'tatasip' for '917252818157' from 10.50.185.2:5060 42955 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] netsock2.c: Using SIP RTP TOS bits 184 42956 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] netsock2.c: Using SIP RTP CoS mark 5 42957 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Got SDP version 14413 and unique parts [BN4000 468 IN IP4 10.50.185.2] 42958 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Found RTP audio format 0 42959 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Found RTP audio format 8 42960 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Found RTP audio format 18 42961 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Found RTP audio format 97 42962 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Found audio description format telephone-event for ID 97 42963 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Capabilities: us - (alaw|ulaw|g729), peer - audio=(ulaw|alaw|g729)/video=(nothing)/text=(nothing), combined - (alaw|ulaw|g729) 42964 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) 42965 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Peer audio RTP is at port 10.50.185.2:64112 42966 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Looking for 6614100 in tata (domain 10.50.192.54) 42967 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: 42968 <--- Reliably Transmitting (no NAT) to 10.50.185.2:5060 ---> 42969 SIP/2.0 404 Not Found 42970 Via: SIP/2.0/UDP 10.50.185.2:5060;branch=z9hG4bK-53d6d23e-25c1b4-937ca7c3-7fb64025ab20;received=10.50.185.2 42971 From: "917252818157";tag=BN1705504033-1-1613807044-386724751 42972 To: "1356614101";tag=as581fa049 42973 Call-ID: 6aa7519e-43332398-25c1b4-7fb6170b1c88-cdc0a20a-13c4-759 42974 CSeq: 22943 INVITE 42975 Server: FPBX-15.0.16.81(16.13.0) 42976 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE 42977 Supported: replaces, timer 42978 Content-Length: 0 42979 42980 42981 <------------> 42982 [2021-02-20 07:44:06] NOTICE[21530][C-00000005] chan_sip.c: Call from 'tatasip' (10.50.185.2:5060) to extension '6614100' rejected because extension not found in context 'tata '. 42983 [2021-02-20 07:44:06] VERBOSE[21530][C-00000005] chan_sip.c: Scheduling destruction of SIP dialog '6aa7519e-43332398-25c1b4-7fb6170b1c88-cdc0a20a-13c4-759' in 32000 ms (Method: INVITE) 42984 [2021-02-20 07:44:06] VERBOSE[21530] chan_sip.c: 42985 <--- SIP read from UDP:10.50.185.2:5060 ---> 42986 ACK sip:6614100@10.50.192.54:5060;transport=UDP SIP/2.0 42987 From: "917252818157";tag=BN1705504033-1-1613807044-386724751 42988 To: "1356614101";tag=as581fa049 42989 Call-ID: 6aa7519e-43332398-25c1b4-7fb6170b1c88-cdc0a20a-13c4-759 42990 CSeq: 22943 ACK 42991 Via: SIP/2.0/UDP 10.50.185.2:5060;branch=z9hG4bK-53d6d23e-25c1b4-937ca7c3-7fb64025ab20 42992 Max-Forwards: 70 42993 Contact: 42994 Content-Length: 0 42995 42996 <-------------> 42997 [2021-02-20 07:44:06] VERBOSE[21530] chan_sip.c: --- (9 headers 0 lines) --- 42998 [2021-02-20 07:44:06] VERBOSE[21530] chan_sip.c: Really destroying SIP dialog '6aa7519e-43332398-25c1b4-7fb6170b1c88-cdc0a20a-13c4-759' Method: ACK 42999 [2021-02-20 07:44:14] VERBOSE[21530] chan_sip.c: 43000 <--- SIP read from UDP:10.100.148.1:51122 ---> 43001 43002 <-------------> 43003 [2021-02-20 07:44:24] VERBOSE[21530] chan_sip.c: Reliably Transmitting (NAT) to 10.100.148.1:51122: 43004 OPTIONS sip:2002@10.100.148.94:51122;ob SIP/2.0 43005 Via: SIP/2.0/UDP 10.100.51.227:5060;branch=z9hG4bK4015cfe3;rport 43006 Max-Forwards: 70 43007 From: "Unknown" ;tag=as6573915a 43008 To: 43009 Contact: 43010 Call-ID: 6fe39304372b6dc457cd091962cfd267@10.100.51.227:5060 43011 CSeq: 102 OPTIONS 43012 User-Agent: FPBX-15.0.16.81(16.13.0) 43013 Date: Sat, 20 Feb 2021 07:44:24 GMT 43014 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE 43015 Supported: replaces, timer 43016 Content-Length: 0 43017 43018 43019 --- 43020 [2021-02-20 07:44:24] VERBOSE[21530] chan_sip.c: 43021 <--- SIP read from UDP:10.100.148.1:51122 ---> 43022 SIP/2.0 200 OK 43023 Via: SIP/2.0/UDP 10.100.51.227:5060;rport=5060;received=10.100.51.227;branch=z9hG4bK4015cfe3 43024 Call-ID: 6fe39304372b6dc457cd091962cfd267@10.100.51.227:5060 43025 From: "Unknown" ;tag=as6573915a 43026 To: ;tag=z9hG4bK4015cfe3 43027 CSeq: 102 OPTIONS 43028 Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS 43029 Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain 43030 Supported: replaces, 100rel, timer, norefersub 43031 Allow-Events: presence, message-summary, refer 43032 User-Agent: MicroSIP/3.20.3 43033 Content-Length: 0 43034 43035 <-------------> 43036 [2021-02-20 07:44:24] VERBOSE[21530] chan_sip.c: --- (12 headers 0 lines) --- 43037 [2021-02-20 07:44:24] VERBOSE[21530] chan_sip.c: Really destroying SIP dialog '6fe39304372b6dc457cd091962cfd267@10.100.51.227:5060' Method: OPTIONS 43038 [2021-02-20 07:44:29] VERBOSE[21530] chan_sip.c: 43039 <--- SIP read from UDP:10.100.148.1:51122 ---> 43040 43041 <------------->