Cannot make outbound calls - config problem of trunk

FreePBX Providers
1

Heya :slight_smile: I’m starting to despair after 3 days of debugging.

Essentially, I think something in my configuration is wrong on my trunk. From what I understood (absolute FreePBX newbie, user since 3 days) something in the outbound invitation is wrong. When I set up the trunk in a Softphone, everything works great. When I set it up in FreePBX I can only get inbound calls. The routes seem OK and the ‘number is not available’ comes from my provider side.

This is where I went from, a FritzBox config file I downloaded and decyphered. Yes, this is from Post Luxembourg. Yes, I do know my password. I think I’m one of very few people trying this.

voipcfg {
        dnsport = 7077;
        rtpport_start = 7078;
        sip_srcport = 5060;
        ua1 {
                enabled = yes;
                username = "***";
                authname = "***";
                authname_needed = yes;
                passwd = "***";
                registrar = "voip.dt.ept.lu";
                ttl = 30m;
                sipping_enabled = no;
                sipping_interval = 280s;
                name = "****";
                providername = "";
                voip_providerlist_id = "other";
                ims_client = no;
                with_displayname = no;
                read_from_displayname = yes;
                dtmfcfg = dtmfcfg_automatic;
                rtpevent_keep_packetrate = no;
                register_failwait = 0w;
                register_failwaitmax = 30m;
                register_failover_fallback_process = no;
                stunserver = "";
                stunserverport = 3478;
                use_internat_calling_numb = no;
                is_nat_aware = no;
                localip = 0.0.0.0;
                protocolprefer = protocolprefer_ipv4only;
                ignore_received_header = no;
                always_clir = no;
                clirtype = clir_displayname;
                reject_anonymous_call_with_433 = no;
                colptype = colp_none;
                clipnstype = clipns_off;
                vad_enabled = no;
                only_one_dialog = no;
                presence_supported = no;
                mwi_supported = no;
                mwi_inmemoria = no;
                ccbs_supported = no;
                reg_support = regsupport_auto;
                packetization = packetization_fixed;
                tx_packetsize_in_ms = 20;
                xrtp_periodic = 0;
                reject_refer = yes;
                sip_instance = no;
                no_register_fetch = yes;
                do_not_register = no;
                only_call_from_registrar = no;
                mobile_capability = voip_over_mobile_all;
                invite_without_register_allowed = no;
                outboundproxy = "residential.dt.ept.lu";
                outboundproxy_without_route_header = no;
                factory_3pty_uri = "";
                no_hold_speech = no;
                dditype = ddi_none;
                ddireception = "";
                ddimynumber_with_plusprefix = no;
                webui_trunk_id = "";
                alias_head_number = "";
                cfxsignaling = cfx_standard;
                backup_wanted = no;
                use_session_timer = no;
                use_rport = yes;
                add_rtpmap_for_all_codecs = no;
                answer_only_one_codec = no;
                without_annexb_no = no;
                transport_type = transport_unspec;
                srtp_supported = no;
                crypto_avp_mode = crypto_mode_avp_only;
                use_488_for_no_t38 = no;
                g726_via_rfc3551 = no;
                no_g726_32_offer_with_pt2 = no;
                g726_fixed_ptime30 = no;
                dtmf_inband_on_g711g722 = no;
                enable_3xx = yes;
                t38_reinvite_from_remote = no;
                use_t38version0 = no;
                rtcp_xr_media_attribute = no;
                ptime_a_attribute = yes;
                tones_and_announcements_for_service = no;
                read_p_asserted_identity_header = no;
                route_always_over_internet = no;
                sipiface = sipiface_automatic;
                altc_attribute_rfc6947 = no;
                send_extended_sip_client_info = no;
                gui_readonly = yes;
                convertstate = 0;
                snmp_instance = 0;
                loopback_client_username_fos = "";
                loopback_client_username_pass_through = "";
                directloopback_client_username = "";
                call_deflection = no;
        }
}
2

Next, here are two logs. The first is from my softphone where everything works great, inbound and outbound. (I hope I isolated the right packets, if not just tell me, I have the whole logs)

DEBUG | 20211220-123754.600 | Z:APP | 26384 | Call.cpp:678 | Call (Z86dcce85ca5517f5846c5e2d) (***callednumber***) created.
DEBUG | 20211220-123754.600 | Z:APP | 26384 | ExternalPluginManager.cpp:100 | External Plugin Manager new call state outgoing
DEBUG | 20211220-123754.600 | Z:APP | 26384 | ExternalPluginLoadingManager.cpp:75 | External Plugin state change: SetHook to state on
DEBUG | 20211220-123754.600 | Z:APP | 26384 | ExternalPluginLoadingManager.cpp:91 | External Plugin state change: SetHold to state off
DEBUG | 20211220-123754.600 | Z:APP | 26384 | ExternalPluginLoadingManager.cpp:83 | External Plugin state change: SetRing to state off
DEBUG | 20211220-123754.601 | Z:APP | 26384 | ExternalPluginManager.cpp:100 | External Plugin Manager new call state active_call
DEBUG | 20211220-123754.601 | Z:APP | 26384 | ExternalPluginLoadingManager.cpp:83 | External Plugin state change: SetRing to state off
DEBUG | 20211220-123754.601 | Z:APP | 26384 | ExternalPluginLoadingManager.cpp:75 | External Plugin state change: SetHook to state off
DEBUG | 20211220-123754.601 | Z:APP | 26384 | Phone.cpp:583 | UpdateSound: Active call: 1230054567968; Ringing calls count: 0; Ring when talking (bool)true
DEBUG | 20211220-123754.601 | Z:APP | 26384 | Phone.cpp:601 | Stopping sound on normal device.
DEBUG | 20211220-123754.645 | Z:APP | 26384 | Phone.cpp:583 | UpdateSound: Active call: 1230054567968; Ringing calls count: 0; Ring when talking (bool)true
DEBUG | 20211220-123754.645 | Z:APP | 26384 | Phone.cpp:601 | Stopping sound on normal device.
DEBUG | 20211220-123754.645 | Z:APP | 26384 | Phone.Call.cpp:522 | Went into On the phone State.
DEBUG | 20211220-123754.645 | Z:APP | 26384 | ContactSearchCall.cpp:125 | Contact call search (Z5f8ee10a51f9239353c450c6) started (phone = ***callednumber***).
DEBUG | 20211220-123754.646 | Z:APP | 26384 | ContactSearch.cpp:113 | Contact search (Z5f8ee10a51f9239353c450c6) started (limit = 0; matchFlag = 1) for all available contact services.
DEBUG | 20211220-123754.646 | Z:APP | 7392 | Local.cpp:349 | Query begin
DEBUG | 20211220-123754.647 | Z:APP | 7392 | Local.cpp:363 | Query complete
DEBUG | 20211220-123754.659 | Z:APP | 26384 | ContactSearchCall.cpp:140 | Contact call search (Z5f8ee10a51f9239353c450c6) found contact (***callednumber***).
DEBUG | 20211220-123754.666 | Z:APP | 26384 | HistoryService.cpp:157 | History add/update elapsed time = 6ms
DEBUG | 20211220-123754.666 | Z:APP | 26384 | HistoryDetailCommon.cpp:17 | History detail common setting new contact ***callednumber***
DEBUG | 20211220-123754.684 | WRAPPER | 12300 | stun_server.cpp:489 | PollStunPort: successfully resolved socket 3952 on server [ V4 185.117.83.50:3478 UDP targetDomain=stun1.zoiper.com ] to [ V4 ***myIP***:7078 ]
DEBUG | 20211220-123754.684 | WRAPPER | 12300 | call.cpp:102 | Call 0000000000BC82CA state 0 -> 2
DEBUG | 20211220-123754.684 | WRAPPER | 12300 | sip_call.cpp:672 | CreateRtpStream: 0000011E64DC3CA0, flags= 5
DEBUG | 20211220-123754.684 | WRAPPER | 12300 | neteq_source.cpp:45 | NetEqSource: 0000011E647EE310
DEBUG | 20211220-123754.684 | WRAPPER | 12300 | neteq_stream.cpp:66 | NetEqStream 0000011E65553010: owner= 0000000000BC82CA
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | rtp_stream.cpp:48 | RtpStream 0000011E65553010
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | rtp_stream.cpp:56 | RtpStream: decoders= [CodecList: Opus/16000, G.722, Tel-event, Tel-event, G.711 mu-law, G.711 a-law, GSM FR]
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | rtp_stream.cpp:213 | SetCollisionState 0000011E65553010: state= 1, maxCollisions= 5
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | smart_rtp_session.cpp:304 | SetCollisionState: will ignore colliding sources unless they match our negotiated peer
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | rtp_stream.cpp:77 | SetLocalAddr 0000011E65553010: addr= [ V4 ***myInternalIP***:7078 ]; socket: 3952
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | rtp_stream.cpp:97 | SetRemoteDestination 0000011E65553010: 0.0.0.0:0
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | rtp_stream.cpp:206 | SetDSCP 0000011E65553010: media= 0
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_stream.cpp:635 | SetMixType 0000011E65553010: type= 0
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:163 | SetStreamMixType: 0000011E647EE310, type= 0
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_stream.cpp:80 | SetStreamMixer 0000011E65553010: old= 0000011E621437F0 new= 0000011E621437F0
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | rtp_stream.cpp:242 | Create 0000011E65553010
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:124 | AddDecoder: 0000011E647EE310, name= Opus/16000 payload= 106
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:124 | AddDecoder: 0000011E647EE310, name= G.722 payload= 9
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:124 | AddDecoder: 0000011E647EE310, name= Tel-event payload= 98
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:124 | AddDecoder: 0000011E647EE310, name= Tel-event payload= 101
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:124 | AddDecoder: 0000011E647EE310, name= G.711 mu-law payload= 0
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:124 | AddDecoder: 0000011E647EE310, name= G.711 a-law payload= 8
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:124 | AddDecoder: 0000011E647EE310, name= GSM FR payload= 3
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_stream.cpp:101 | Create 0000011E65553010
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:57 | Create: 0000011E647EE310
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:438 | Adding decoder G.711 mu-law payload= 0
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:438 | Adding decoder GSM FR payload= 3
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:438 | Adding decoder G.711 a-law payload= 8
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:438 | Adding decoder G.722 payload= 9
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:438 | Adding decoder Tel-event payload= 98
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:438 | Adding decoder Tel-event payload= 101
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:438 | Adding decoder Opus/16000 payload= 106
DEBUG | 20211220-123754.685 | WRAPPER | 12300 | neteq_source.cpp:390 | State: 0000011E647EE310 Initial -> Created
DEBUG | 20211220-123754.686 | WRAPPER | 12300 | neteq_stream.cpp:118 | Create: Output disabled
DEBUG | 20211220-123754.686 | WRAPPER | 12300 | appl_event_queue.cpp:173 | Adding event [class scx::CCallNetworkQualityLevel] to queue
DEBUG | 20211220-123754.686 | WRAPPER | 12300 | neteq_stream.cpp:136 | Create: Initialization complete
DEBUG | 20211220-123754.686 | WRAPPER | 12300 | smart_rtp_session.cpp:85 | OnNewSource: 441DD581
DEBUG | 20211220-123754.687 | WRAPPER | 12300 | smart_rtp_session.cpp:88 | OnNewSource: no address (local source)
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | neteq_stream.cpp:507 | Hold 0000011E65553010
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | neteq_stream.cpp:520 | Hold: Not started
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | rtp_stream.cpp:312 | Start 0000011E65553010
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | neteq_stream.cpp:157 | Start 0000011E65553010
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | neteq_stream.cpp:187 | Start: Already on hold
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | neteq_stream.cpp:325 | StartInputProcess 0000011E65553010: starting after 0ms, absolute time: 318085357
DEBUG | 20211220-123754.689 | WRAPPER | 11376 | neteq_stream.cpp:198 | InternalRun 0000011E65553010
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | appl_event_queue.cpp:173 | Adding event [class scx::CCallSecurityLevel] to queue
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | sip_call.cpp:1292 | SDPGen: Processing payload id 106 as opus/48000 fmtp="sprop-maxcapturerate=16000; minptime=20; useinbandfec=1" (Opus/16000)
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | sip_call.cpp:1292 | SDPGen: Processing payload id 9 as G722/8000 fmtp="" (G.722)
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | sip_call.cpp:1292 | SDPGen: Processing payload id 98 as telephone-event/48000 fmtp="0-16" (Tel-event)
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | sip_call.cpp:1292 | SDPGen: Processing payload id 101 as telephone-event/8000 fmtp="0-16" (Tel-event)
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | sip_call.cpp:1292 | SDPGen: Processing payload id 0 as PCMU/8000 fmtp="" (G.711 mu-law)
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | sip_call.cpp:1292 | SDPGen: Processing payload id 8 as PCMA/8000 fmtp="" (G.711 a-law)
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | sip_call.cpp:1292 | SDPGen: Processing payload id 3 as GSM/8000 fmtp="" (GSM FR)
DEBUG | 20211220-123754.689 | WRAPPER | 22856 | neteq_stream.cpp:294 | Thread started, now= 318085358
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | sip_user.cpp:509 | AddOutboundProxyToProfile: Setting proxy residential.dt.ept.lu
DEBUG | 20211220-123754.689 | WRAPPER | 22856 | neteq_stream.cpp:295 | Input schedule=      318085357
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | app_dialogs.cpp:66 | AppDialogSet 0000011E65056470
DEBUG | 20211220-123754.689 | WRAPPER | 22856 | neteq_stream.cpp:296 | Output schedule=     9223372036854775807
DEBUG | 20211220-123754.689 | WRAPPER | 12300 | app_dialogs.cpp:71 | User id= 0000000000BC812A
DEBUG | 20211220-123754.689 | WRAPPER | 22856 | neteq_stream.cpp:297 | Recording schedule=  9223372036854775807
DEBUG | 20211220-123754.689 | WRAPPER | 22856 | neteq_stream.cpp:298 | Statistics schedule= 9223372036854775807
DEBUG | 20211220-123754.689 | RESIP:DUM | 12300 | BaseCreator.cxx:128 | BaseCreator::makeInitialRequest: Adding Routes header= []
DEBUG | 20211220-123754.689 | RESIP:DUM | 12300 | BaseCreator.cxx:155 | BaseCreator::makeInitialRequest: 

INVITE sip:***callednumber***@voip.dt.ept.lu SIP/2.0
Via: SIP/2.0/ ;branch=z9hG4bK-524287-1---5749c2b5320c966c;rport
Max-Forwards: 70
Contact: <sip:***mynumber***@***myIP***:5060;transport=UDP>
To: <sip:***callednumber***@voip.dt.ept.lu>
From: "Home"<sip:***mynumber***@voip.dt.ept.lu;transport=UDP>;tag=7c43621f
Call-ID: 9meq4Heo-6MY5NIDl1rEag..
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
Allow-Events: presence, kpml, talk
Content-Length: 0


DEBUG | 20211220-123754.689 | RESIP:DUM | 12300 | DialogSet.cxx:54 |  ************* Created DialogSet(UAC)  -- 9meq4Heo-6MY5NIDl1rEag..-7c43621f*************
DEBUG | 20211220-123754.690 | RESIP:DUM | 12300 | DialogUsageManager.cxx:1011 | SEND: 

INVITE sip:***callednumber***@voip.dt.ept.lu;transport=UDP SIP/2.0
Via: SIP/2.0/ ;branch=z9hG4bK-524287-1---30928df46b6af4f1;rport
Max-Forwards: 70
Contact: <sip:***mynumber***@***myIP***:5060;transport=UDP>
To: <sip:***callednumber***@voip.dt.ept.lu>
From: "Home"<sip:***mynumber***@voip.dt.ept.lu;transport=UDP>;tag=7c43621f
Call-ID: 9meq4Heo-6MY5NIDl1rEag..
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
Content-Type: application/sdp
User-Agent: Z 5.5.8 v2.10.17.2
Allow-Events: presence, kpml, talk
Content-Length: 330

v=0
o=Z 318085358 1 IN IP4 ***myIP***
s=Z
c=IN IP4 ***myIP***
t=0 0
m=audio 7078 RTP/AVP 106 9 98 101 0 8 3
a=rtpmap:106 opus/48000/2
a=fmtp:106 sprop-maxcapturerate=16000; minptime=20; useinbandfec=1
a=rtpmap:98 telephone-event/48000
a=fmtp:98 0-16
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=sendrecv

DEBUG | 20211220-123754.690 | RESIP:DUM | 12300 | DialogId.cxx:50 | DialogId::DialogId: 9meq4Heo-6MY5NIDl1rEag..-7c43621f-
DEBUG | 20211220-123754.690 | RESIP:DUM | 12300 | DialogUsageManager.cxx:1138 | Using outbound proxy: sip:residential.dt.ept.lu;transport=UDP;lr -> SipReq:  INVITE ***callednumber***@voip.dt.ept.lu tid=30928df46b6af4f1 cseq=1 INVITE contact=***mynumber***@***myIP***:5060 / 1 from(tu)
DEBUG | 20211220-123754.690 | RESIP:DUM | 12300 | DialogUsageManager.cxx:1165 | Sending to outbound uri
DEBUG | 20211220-123754.690 | WRAPPER | 12300 | appl_event_queue.cpp:167 | Posting event
DEBUG | 20211220-123754.690 | WRAPPER | 12300 | appl_event_queue.cpp:45 | Notify: event= onCallCreate(0000000000BC812A, 0000000000BC82CA, ***callednumber***)
DEBUG | 20211220-123754.690 | WRAPPER | 12300 | appl_event_queue.cpp:145 | SetCallCreateSent, cur= 0
DEBUG | 20211220-123754.690 | WRAPPER | 12300 | appl_event_queue.cpp:150 | Posting queued event [class scx::CCallNetworkQualityLevel]
DEBUG | 20211220-123754.690 | WRAPPER | 12300 | appl_event_queue.cpp:45 | Notify: event= [class scx::CCallNetworkQualityLevel]
DEBUG | 20211220-123754.690 | WRAPPER | 12300 | appl_event_queue.cpp:150 | Posting queued event [class scx::CCallSecurityLevel]
DEBUG | 20211220-123754.690 | WRAPPER | 12300 | appl_event_queue.cpp:45 | Notify: event= [class scx::CCallSecurityLevel]
DEBUG | 20211220-123754.690 | WRAPPER | 12300 | sip_call.cpp:2771 | SetEventCallCreatedStatus: call= 0000000000BC82CA status: 1 -> 3
DEBUG | 20211220-123754.690 | WRAPPER | 12300 | appl_event_queue.cpp:145 | SetCallCreateSent, cur= 1
DEBUG | 20211220-123754.690 | RESIP:TRANSACTION | 12300 | TimerQueue.cxx:50 | Adding timer: Timer B tid=30928df46b6af4f1 ms=32000
DEBUG | 20211220-123754.690 | RESIP:DNS | 12300 | DnsResult.cxx:262 | DnsResult::lookup sip:residential.dt.ept.lu;transport=UDP;lr
DEBUG | 20211220-123754.690 | RESIP:DNS | 12300 | AresDns.cxx:844 | New UDP socket, FD 4020
DEBUG | 20211220-123754.691 | RESIP:DNS | 12300 | AresDns.cxx:838 | Active FD 4020, readable= 1, writable= 0
DEBUG | 20211220-123754.691 | Z:APP | 26384 | Phone.Call.cpp:963 | History filter refresh request because of a call repalce contact grouped by (2).
DEBUG | 20211220-123754.695 | RESIP:DNS | 12300 | DnsStub.cxx:67 | SRV Result: _sip._udp.residential.dt.ept.lu lookup failed: Domain name not found
DEBUG | 20211220-123754.695 | RESIP:DNS | 12300 | AresDns.cxx:834 | Closing FD 4020
DEBUG | 20211220-123754.695 | RESIP:DNS | 12300 | DnsStub.cxx:49 | Host(A) Result: residential.dt.ept.lu(A)--> 213.166.61.116
DEBUG | 20211220-123754.695 | RESIP:DNS | 12300 | AresDns.cxx:844 | New UDP socket, FD 4020
DEBUG | 20211220-123754.695 | RESIP:DNS | 12300 | AresDns.cxx:838 | Active FD 4020, readable= 1, writable= 0
DEBUG | 20211220-123754.699 | Z:APP | 26384 | HistoryCountFilter.cpp:86 | Change filter (1230025821904) (***callednumber***) status started.
DEBUG | 20211220-123754.699 | Z:APP | 26384 | HistoryCountFilter.cpp:89 | Change filter (1230025821904) elapsed time = 0ms
DEBUG | 20211220-123754.703 | RESIP:DNS | 12300 | DnsStub.cxx:56 | Host(AAAA) Result: residential.dt.ept.lu lookup failed: DNS server returned answer with no data
DEBUG | 20211220-123754.703 | RESIP:DNS | 12300 | AresDns.cxx:834 | Closing FD 4020
DEBUG | 20211220-123754.703 | RESIP:TRANSACTION | 12300 | TimerQueue.cxx:50 | Adding timer: Timer A tid=30928df46b6af4f1 ms=500
DEBUG | 20211220-123754.703 | RESIP:TRANSPORT | 12300 | TransportSelector.cxx:1054 | Found transport: [ V4 0.0.0.0:5060 UDP flowKey=3940 transportKey=1 ]
DEBUG | 20211220-123754.710 | Z:APP | 26384 | HistoryCountFilter.cpp:86 | Change filter (1230025823472) (***callednumber***) status started.
DEBUG | 20211220-123754.710 | Z:APP | 26384 | HistoryCountFilter.cpp:89 | Change filter (1230025823472) elapsed time = 0ms
INFO | 20211220-123754.711 | Z:APP | 26384 | Call.cpp:49 | Call Z86dcce85ca5517f5846c5e2d found contact 1
DEBUG | 20211220-123754.711 | Z:APP | 26384 | ContactSearch.cpp:222 | Contact search (Z5f8ee10a51f9239353c450c6) finished elapsed time = 64ms
DEBUG | 20211220-123754.712 | RESIP:TRANSPORT | 12300 | TransportSelector.cxx:990 | Looked up source for destination: [ V4 213.166.61.116:5060 UDP targetDomain=residential.dt.ept.lu ] -> [ V4 ***myInternalIP***:0 UDP targetDomain=residential.dt.ept.lu ] sent-by= sent-port=0
DEBUG | 20211220-123754.712 | Z:APP | 26384 | ContactSearchCall.cpp:157 | Contact call search (Z5f8ee10a51f9239353c450c6) finished (service ident = ContactServiceLocal).
DEBUG | 20211220-123754.712 | Z:APP | 26384 | Contacts.cpp:509 | CONTACTS : Filter completed; Service name = Zoiper5 Contact Service; Total contact count = 0
DEBUG | 20211220-123754.712 | RESIP:TRANSPORT | 12300 | TransportSelector.cxx:1407 | Transmitting to [ V4 213.166.61.116:5060 UDP targetDomain=residential.dt.ept.lu transportKey=1 ] tlsDomain= via [ V4 ***myInternalIP***:5060 UDP targetDomain=residential.dt.ept.lu ]

INVITE sip:***callednumber***@voip.dt.ept.lu;transport=UDP SIP/2.0
Via: SIP/2.0/UDP ***myInternalIP***:5060;branch=z9hG4bK-524287-1---30928df46b6af4f1;rport
Max-Forwards: 70
Contact: <sip:***mynumber***@***myIP***:5060;transport=UDP>
To: <sip:***callednumber***@voip.dt.ept.lu>
From: "Home"<sip:***mynumber***@voip.dt.ept.lu;transport=UDP>;tag=7c43621f
Call-ID: 9meq4Heo-6MY5NIDl1rEag..
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
Content-Type: application/sdp
User-Agent: Z 5.5.8 v2.10.17.2
Allow-Events: presence, kpml, talk
Content-Length: 330

v=0
o=Z 318085358 1 IN IP4 ***myIP***
s=Z
c=IN IP4 ***myIP***
t=0 0
m=audio 7078 RTP/AVP 106 9 98 101 0 8 3
a=rtpmap:106 opus/48000/2
a=fmtp:106 sprop-maxcapturerate=16000; minptime=20; useinbandfec=1
a=rtpmap:98 telephone-event/48000
a=fmtp:98 0-16
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=sendrecv
sigcomp id=
INFO | 20211220-123754.712 | RESIP:TRANSPORT | 12300 | UdpTransport.cxx:309 | Seaching address: 213.166.61.116; port: 5060
INFO | 20211220-123754.712 | RESIP:TRANSPORT | 12300 | UdpTransport.cxx:319 | processTxOne: getaddrinfo returned: 0
INFO | 20211220-123754.712 | RESIP:TRANSPORT | 12300 | UdpTransport.cxx:332 | processTxOne: Send 914 bytes, sent 914 instead
DEBUG | 20211220-123754.721 | Z:APP | 7392 | Local.cpp:349 | Query begin
DEBUG | 20211220-123754.721 | Z:APP | 26384 | HistoryService.cpp:101 | History refreshing filters grouped by (2).
DEBUG | 20211220-123754.721 | Z:APP | 26384 | HistoryFilter.cpp:237 | History filter (Z1b53b17b36ad2f3e9a1cf5d) started (limit = 20; groupMode = 2).
DEBUG | 20211220-123754.721 | Z:APP | 26384 | HistoryFilter.cpp:237 | History filter (Zb26193a2f19d84afb2dc8636) started (limit = 20; groupMode = 2).
DEBUG | 20211220-123754.721 | Z:APP | 26384 | HistoryFilter.cpp:237 | History filter (Z58434f64e4f4ca09dc3f9525) started (limit = 20; groupMode = 2).
DEBUG | 20211220-123754.722 | Z:APP | 7392 | Local.cpp:363 | Query complete
DEBUG | 20211220-123754.727 | RESIP:TRANSPORT | 12300 | Transport.cxx:397 | incoming from: [ V4 213.166.61.116:5060 UDP flowKey=3940 transportKey=1 ]
DEBUG | 20211220-123754.727 | RESIP:TRANSACTION | 12300 | TuSelector.cxx:73 | Send to TU: DialogUsageManager size=0 

SIP/2.0 100 Trying
Via: SIP/2.0/UDP ***myInternalIP***:5060;branch=z9hG4bK-524287-1---30928df46b6af4f1;rport=5060
To: <sip:***callednumber***@voip.dt.ept.lu>;tag=gK0081b0eb
From: "Home"<sip:***mynumber***@voip.dt.ept.lu;transport=UDP>;tag=7c43621f
Call-ID: 9meq4Heo-6MY5NIDl1rEag..
CSeq: 1 INVITE
Content-Length: 0


DEBUG | 20211220-123754.727 | RESIP:DNS | 12300 | DnsResult.cxx:254 | Whitelisting residential.dt.ept.lu(1): 213.166.61.116
DEBUG | 20211220-123754.727 | RESIP:DNS | 12300 | RRVip.cxx:128 | updating an existing vip: 213.166.61.116 with 213.166.61.116
DEBUG | 20211220-123754.728 | RESIP:DUM | 12300 | DialogUsageManager.cxx:1627 | Got: SipResp: 100 tid=30928df46b6af4f1 cseq=1 INVITE / 1 from(wire)
DEBUG | 20211220-123754.728 | RESIP:DUM | 12300 | DialogUsageManager.cxx:2177 | DialogUsageManager::processResponse: 

SipResp: 100 tid=30928df46b6af4f1 cseq=1 INVITE / 1 from(wire)
DEBUG | 20211220-123754.769 | Z:APP | 26384 | HistoryFilter.cpp:360 | History filter (Z58434f64e4f4ca09dc3f9525) finished (limit = 20; groupMode = 2; count = 0
DEBUG | 20211220-123754.769 | Z:APP | 26384 | HistoryFilter.cpp:363 | History filter (Z58434f64e4f4ca09dc3f9525) elapsed time = 47ms
DEBUG | 20211220-123754.770 | Z:APP | 26384 | Contacts.cpp:509 | CONTACTS : Filter completed; Service name = Zoiper5 Contact Service; Total contact count = 0
DEBUG | 20211220-123754.773 | Z:APP | 26384 | HistoryFilter.cpp:360 | History filter (Z1b53b17b36ad2f3e9a1cf5d) finished (limit = 20; groupMode = 2; count = 6
DEBUG | 20211220-123754.773 | Z:APP | 26384 | HistoryFilter.cpp:363 | History filter (Z1b53b17b36ad2f3e9a1cf5d) elapsed time = 52ms
DEBUG | 20211220-123754.823 | Z:APP | 26384 | HistoryFilter.cpp:360 | History filter (Zb26193a2f19d84afb2dc8636) finished (limit = 20; groupMode = 2; count = 6
DEBUG | 20211220-123754.823 | Z:APP | 26384 | HistoryFilter.cpp:363 | History filter (Zb26193a2f19d84afb2dc8636) elapsed time = 101ms
DEBUG | 20211220-123756.130 | RESIP:TRANSPORT | 12300 | Transport.cxx:397 | incoming from: [ V4 213.166.61.116:5060 UDP flowKey=3940 transportKey=1 ]
DEBUG | 20211220-123756.130 | RESIP:TRANSACTION | 12300 | TuSelector.cxx:73 | Send to TU: DialogUsageManager size=0 

SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP ***myInternalIP***:5060;branch=z9hG4bK-524287-1---30928df46b6af4f1;rport=5060
Contact: <sip:***callednumber***@213.166.61.116:5060>
To: <sip:***callednumber***@voip.dt.ept.lu>;tag=gK0081b0eb
From: "Home"<sip:***mynumber***@voip.dt.ept.lu;transport=UDP>;tag=7c43621f
Call-ID: 9meq4Heo-6MY5NIDl1rEag..
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, BYE, REGISTER, REFER, INFO, SUBSCRIBE, NOTIFY, UPDATE, OPTIONS, MESSAGE, PUBLISH
Content-Disposition: session; handling=required
Content-Type: application/sdp
Supported: tdialog
Privacy: none
P-Asserted-Identity: <sip:***callednumber***@213.166.61.116;user=phone>
Session: Media
Content-Length: 178

v=0
o=- 987518 350542 IN IP4 213.166.61.118
s=SIP Media Capabilities
c=IN IP4 213.166.61.118
t=0 0
m=audio 44302 RTP/AVP 8
a=maxptime:20
a=rtpmap:8 PCMA/8000
a=sendrecv
3

FreePBX log where it does NOT work.

[2021-12-20 12:41:22] VERBOSE[3237] res_pjsip_logger.c: <--- Received SIP request (907 bytes) from UDP:***myPCIP***:5060 --->   

74136   INVITE sip:32***numberToBeCalled***@***myFreePBXIP***;transport=UDP SIP/2.0 

74137   Via: SIP/2.0/UDP ***myPCIP***:5060;branch=z9hG4bK-524287-1---31935ebd141785fc;rport 

74138   Max-Forwards: 70    

74139   Contact: <sip:2@***myPCIP***:5060;transport=UDP>    

74140   To: <sip:32***numberToBeCalled***@***myFreePBXIP***>    

74141   From: "Home"<sip:2@***myFreePBXIP***;transport=UDP>;tag=1f64d47f    

74142   Call-ID: JKVcjKdhlvEjcZKdG5QHKA..   

74143   CSeq: 1 INVITE  

74144   Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE   

74145   Content-Type: application/sdp   

74146   User-Agent: Z 5.5.8 v2.10.17.2  

74147   Allow-Events: presence, kpml, talk  

74148   Content-Length: 332 

74149       

74150   v=0 

74151   o=Z 321892619 1 IN IP4 ***myPCIP*** 

74152   s=Z 

74153   c=IN IP4 ***myPCIP***   

74154   t=0 0   

74155   m=audio 7078 RTP/AVP 106 9 98 101 0 8 3 

74156   a=rtpmap:106 opus/48000/2   

74157   a=fmtp:106 sprop-maxcapturerate=16000; minptime=20; useinbandfec=1  

74158   a=rtpmap:98 telephone-event/48000   

74159   a=fmtp:98 0-16  

74160   a=rtpmap:101 telephone-event/8000   

74161   a=fmtp:101 0-16 

74162   a=sendrecv  

74163       

74164   [2021-12-20 12:41:22] VERBOSE[16464] res_pjsip_logger.c: <--- Transmitting SIP response (523 bytes) to UDP:***myPCIP***:5060 --->   

74165   SIP/2.0 401 Unauthorized    

74166   Via: SIP/2.0/UDP ***myPCIP***:5060;rport=5060;received=***myPCIP***;branch=z9hG4bK-524287-1---31935ebd141785fc  

74167   Call-ID: JKVcjKdhlvEjcZKdG5QHKA..   

74168   From: "Home" <sip:2@***myFreePBXIP***>;tag=1f64d47f 

74169   To: <sip:32***numberToBeCalled***@***myFreePBXIP***>;tag=z9hG4bK-524287-1---31935ebd141785fc    

74170   CSeq: 1 INVITE  

74171   WWW-Authenticate: Digest realm="asterisk",nonce="1640004082/650c299487115bf10ee64c2f3df962a0",opaque="52315e5544c933a0",algorithm=md5,qop="auth"    

74172   Server: FPBX-15.0.17.64(16.17.0)    

74173   Content-Length: 0   

74174       

74175       

74176   [2021-12-20 12:41:22] VERBOSE[3237] res_pjsip_logger.c: <--- Received SIP request (373 bytes) from UDP:***myPCIP***:5060 --->   

74177   ACK sip:32***numberToBeCalled***@***myFreePBXIP***;transport=UDP SIP/2.0    

74178   Via: SIP/2.0/UDP ***myPCIP***:5060;branch=z9hG4bK-524287-1---31935ebd141785fc;rport 

74179   Max-Forwards: 70    

74180   To: <sip:32***numberToBeCalled***@***myFreePBXIP***>;tag=z9hG4bK-524287-1---31935ebd141785fc    

74181   From: "Home"<sip:2@***myFreePBXIP***;transport=UDP>;tag=1f64d47f    

74182   Call-ID: JKVcjKdhlvEjcZKdG5QHKA..   

74183   CSeq: 1 ACK 

74184   Content-Length: 0   

74185       

74186       

74187   [2021-12-20 12:41:22] VERBOSE[3237] res_pjsip_logger.c: <--- Received SIP request (1210 bytes) from UDP:***myPCIP***:5060 --->  

74188   INVITE sip:32***numberToBeCalled***@***myFreePBXIP***;transport=UDP SIP/2.0 

74189   Via: SIP/2.0/UDP ***myPCIP***:5060;branch=z9hG4bK-524287-1---b9620f3096d03d35;rport 

74190   Max-Forwards: 70    

74191   Contact: <sip:2@***myPCIP***:5060;transport=UDP>    

74192   To: <sip:32***numberToBeCalled***@***myFreePBXIP***>    

74193   From: "Home"<sip:2@***myFreePBXIP***;transport=UDP>;tag=1f64d47f    

74194   Call-ID: JKVcjKdhlvEjcZKdG5QHKA..   

74195   CSeq: 2 INVITE  

74196   Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE   

74197   Content-Type: application/sdp   

74198   User-Agent: Z 5.5.8 v2.10.17.2  

74199   Authorization: Digest username="2",realm="asterisk",nonce="1640004082/650c299487115bf10ee64c2f3df962a0",uri="sip:32***numberToBeCalled***@***myFreePBXIP***;transport=UDP",response="8de373e2e5dc3dc7ef994780f27b4d63",cnonce="eaf2b4b2d229f75bbb2cfd1bbdaa28a5",nc=00000001,qop=auth,algorithm=md5,opaque="52315e5544c933a0"   

74200   Allow-Events: presence, kpml, talk  

74201   Content-Length: 332 

74202       

74203   v=0 

74204   o=Z 321892619 1 IN IP4 ***myPCIP*** 

74205   s=Z 

74206   c=IN IP4 ***myPCIP***   

74207   t=0 0   

74208   m=audio 7078 RTP/AVP 106 9 98 101 0 8 3 

74209   a=rtpmap:106 opus/48000/2   

74210   a=fmtp:106 sprop-maxcapturerate=16000; minptime=20; useinbandfec=1  

74211   a=rtpmap:98 telephone-event/48000   

74212   a=fmtp:98 0-16  

74213   a=rtpmap:101 telephone-event/8000   

74214   a=fmtp:101 0-16 

74215   a=sendrecv  

74216       

74217   [2021-12-20 12:41:22] VERBOSE[16464] res_pjsip_logger.c: <--- Transmitting SIP response (331 bytes) to UDP:***myPCIP***:5060 --->   

74218   SIP/2.0 100 Trying  

74219   Via: SIP/2.0/UDP ***myPCIP***:5060;rport=5060;received=***myPCIP***;branch=z9hG4bK-524287-1---b9620f3096d03d35  

74220   Call-ID: JKVcjKdhlvEjcZKdG5QHKA..   

74221   From: "Home" <sip:2@***myFreePBXIP***>;tag=1f64d47f 

74222   To: <sip:32***numberToBeCalled***@***myFreePBXIP***>    

74223   CSeq: 2 INVITE  

74224   Server: FPBX-15.0.17.64(16.17.0)    

74225   Content-Length: 0   

74226       

74227       

74228   [2021-12-20 12:41:23] VERBOSE[16464] netsock2.c: Using SIP RTP Audio TOS bits 184   

74229   [2021-12-20 12:41:23] VERBOSE[16464] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.  

74230   [2021-12-20 12:41:23] VERBOSE[16464] netsock2.c: Using SIP RTP Audio CoS mark 5 

74231   [2021-12-20 12:41:23] VERBOSE[5531][C-00000016] pbx.c: Executing [32***numberToBeCalled***@from-internal:1] Macro("PJSIP/2-00000025", "user-callerid,LIMIT,EXTERNAL,") in new stack 

74232   [2021-12-20 12:41:23] VERBOSE[5531][C-00000016] pbx.c: Executing [s@macro-user-callerid:1] Set("PJSIP/2-00000025", "TOUCH_MONITOR=1640004083.37") in new stack  

74233   [2021-12-20 12:41:23] VERBOSE[5531][C-00000016] pbx.c: Executing [s@macro-user-callerid:2] Set("PJSIP/2-00000025", "CHANCONTEXT=") in new stack 

74234   [2021-12-20 12:41:23] VERBOSE[5531][C-00000016] pbx.c: Executing [s@macro-user-callerid:3] Set("PJSIP/2-00000025", "CHANCONTEXT=") in new stack 

74391   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] pbx.c: Executing [s@func-apply-sipheaders:6] Set("PJSIP/***myPhoneNumber***-00000026", "sipheader=unset") in new stack  

74392   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] pbx.c: Executing [s@func-apply-sipheaders:7] ExecIf("PJSIP/***myPhoneNumber***-00000026", "0?SIPRemoveHeader(Alert-Info:)") in new stack    

74393   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] pbx.c: Executing [s@func-apply-sipheaders:8] ExecIf("PJSIP/***myPhoneNumber***-00000026", "1?Set(PJSIP_HEADER(remove,Alert-Info)=)") in new stack   

74394   [2021-12-20 12:41:24] ERROR[16464] res_pjsip_header_funcs.c: No headers had been previously added to this session.  

74395   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] pbx.c: Executing [s@func-apply-sipheaders:9] ExecIf("PJSIP/***myPhoneNumber***-00000026", "0?Set(sipheader=<http://127.0.0.1>;info=unset)") in new stack    

74396   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] pbx.c: Executing [s@func-apply-sipheaders:10] ExecIf("PJSIP/***myPhoneNumber***-00000026", "0?Set(sipheader=<http://127.0.0.1>unset)") in new stack 

74397   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] pbx.c: Executing [s@func-apply-sipheaders:11] ExecIf("PJSIP/***myPhoneNumber***-00000026", "0?SIPAddHeader(Alert-Info:unset)") in new stack 

74398   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] pbx.c: Executing [s@func-apply-sipheaders:12] ExecIf("PJSIP/***myPhoneNumber***-00000026", "0?Set(PJSIP_HEADER(add,Alert-Info)=unset)") in new stack    

74399   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] pbx.c: Executing [s@func-apply-sipheaders:13] EndWhile("PJSIP/***myPhoneNumber***-00000026", "") in new stack   

74400   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] pbx.c: Executing [s@func-apply-sipheaders:5] While("PJSIP/***myPhoneNumber***-00000026", "0") in new stack  

74401   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] pbx.c: Executing [s@func-apply-sipheaders:14] Return("PJSIP/***myPhoneNumber***-00000026", "") in new stack 

74402   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] app_stack.c: Spawn extension (from-pstn, 32***numberToBeCalled***, 1) exited non-zero on 'PJSIP/***myPhoneNumber***-00000026'   

74403   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] app_stack.c: PJSIP/***myPhoneNumber***-00000026 Internal Gosub(func-apply-sipheaders,s,1(1)) complete GOSUB_RETVAL= 

74404   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] app_dial.c: Called PJSIP/***numberToBeCalled***@***myPhoneNumber*** 

74405   [2021-12-20 12:41:24] VERBOSE[1864] res_pjsip_logger.c: <--- Transmitting SIP request (1081 bytes) to TCP:213.166.61.116:5060 --->  

74406   INVITE sip:residential.dt.ept.lu SIP/2.0    

74407   Via: SIP/2.0/TCP ***myExternalIP***:5060;rport;branch=z9hG4bKPj54bcd297-880e-48c4-bdc9-a03122aa43e9;alias   

74408   From: <sip:***myPhoneNumber***@voip.dt.ept.lu>;tag=0b0d4df6-7240-4d90-9242-7d6c2fad251d 

74409   To: <sip:***numberToBeCalled***@voip.dt.ept.lu> 

74410   Contact: <sip:***myPhoneNumber***@***myExternalIP***:5060;transport=TCP>    

74411   Call-ID: 222a0723-05a0-4dc5-97eb-dabc20c3d609   

74412   CSeq: 12695 INVITE  

74413   Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER   

74414   Supported: 100rel, timer, replaces, norefersub, histinfo    

74415   Session-Expires: 1800   

74416   Min-SE: 90  

74417   Route: <sip:***numberToBeCalled***@voip.dt.ept.lu:5060> 

74418   Max-Forwards: 70    

74419   User-Agent: FPBX-15.0.17.64(16.17.0)    

74420   Content-Type: application/sdp   

74421   Content-Length: 338 

74422       

74423   v=0 

74424   o=- 609016005 609016005 IN IP4 ***myExternalIP***   

74425   s=Asterisk  

74426   c=IN IP4 ***myExternalIP*** 

74427   t=0 0   

74428   m=audio 7090 RTP/AVP 8 0 3 9 111 101    

74429   a=rtpmap:8 PCMA/8000    

74430   a=rtpmap:0 PCMU/8000    

74431   a=rtpmap:3 GSM/8000 

74432   a=rtpmap:9 G722/8000    

74433   a=rtpmap:111 G726-32/8000   

74434   a=rtpmap:101 telephone-event/8000   

74435   a=fmtp:101 0-16 

74436   a=ptime:20  

74437   a=maxptime:150  

74438   a=sendrecv  

74439       

74440   [2021-12-20 12:41:24] VERBOSE[3237] res_pjsip_logger.c: <--- Received SIP response (345 bytes) from TCP:213.166.61.116:5060 --->    

74441   SIP/2.0 100 Trying  

74442   Via: SIP/2.0/TCP ***myExternalIP***:5060;branch=z9hG4bKPj54bcd297-880e-48c4-bdc9-a03122aa43e9;alias;rport=45730 

74443   From: <sip:***myPhoneNumber***@voip.dt.ept.lu>;tag=0b0d4df6-7240-4d90-9242-7d6c2fad251d 

74444   To: <sip:***numberToBeCalled***@voip.dt.ept.lu>;tag=gK08945167  

74445   Call-ID: 222a0723-05a0-4dc5-97eb-dabc20c3d609   

74446   CSeq: 12695 INVITE  

74447   Content-Length: 0   

74448       

74449       

74450   [2021-12-20 12:41:24] VERBOSE[3237] res_pjsip_logger.c: <--- Received SIP response (573 bytes) from TCP:213.166.61.116:5060 --->    

74451   SIP/2.0 180 Ringing 

74452   Via: SIP/2.0/TCP ***myExternalIP***:5060;branch=z9hG4bKPj54bcd297-880e-48c4-bdc9-a03122aa43e9;alias;rport=45730 

74453   From: <sip:***myPhoneNumber***@voip.dt.ept.lu>;tag=0b0d4df6-7240-4d90-9242-7d6c2fad251d 

74454   To: <sip:***numberToBeCalled***@voip.dt.ept.lu>;tag=gK08945167  

74455   Call-ID: 222a0723-05a0-4dc5-97eb-dabc20c3d609   

74456   CSeq: 12695 INVITE  

74457   Contact: <sip:***numberToBeCalled***@213.166.61.116:5060>   

74458   Allow: INVITE,ACK,CANCEL,BYE,REGISTER,REFER,INFO,SUBSCRIBE,NOTIFY,UPDATE,OPTIONS,MESSAGE,PUBLISH    

74459   Supported: tdialog  

74460   P-Asserted-Identity: <sip:213.166.61.116:5060>  

74461   Privacy: none   

74462   Content-Length: 0   

74463       

74464       

74465   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] app_dial.c: PJSIP/***myPhoneNumber***-00000026 is ringing   

74466   [2021-12-20 12:41:24] VERBOSE[16464] res_pjsip_logger.c: <--- Transmitting SIP response (590 bytes) to UDP:***myPCIP***:5060 --->   

74467   SIP/2.0 180 Ringing 

74468   Via: SIP/2.0/UDP ***myPCIP***:5060;rport=5060;received=***myPCIP***;branch=z9hG4bK-524287-1---b9620f3096d03d35  

74469   Call-ID: JKVcjKdhlvEjcZKdG5QHKA..   

74470   From: "Home" <sip:2@***myFreePBXIP***>;tag=1f64d47f 

74471   To: <sip:32***numberToBeCalled***@***myFreePBXIP***>;tag=78c212e6-5b05-4f2d-bb3d-608a0dddb131   

74472   CSeq: 2 INVITE  

74473   Server: FPBX-15.0.17.64(16.17.0)    

74474   Contact: <sip:***myFreePBXIP***:5060>   

74475   Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER   

74476   P-Asserted-Identity: "CID:***myPhoneNumber***" <sip:32***numberToBeCalled***@***myFreePBXIP***> 

74477   Content-Length: 0   

74478       

74479       

74480   [2021-12-20 12:41:24] VERBOSE[3237] res_pjsip_logger.c: <--- Received SIP response (1040 bytes) from TCP:213.166.61.116:5060 --->   

74481   SIP/2.0 200 OK  

74482   Via: SIP/2.0/TCP ***myExternalIP***:5060;branch=z9hG4bKPj54bcd297-880e-48c4-bdc9-a03122aa43e9;alias;rport=45730 

74483   From: <sip:***myPhoneNumber***@voip.dt.ept.lu>;tag=0b0d4df6-7240-4d90-9242-7d6c2fad251d 

74484   To: <sip:***numberToBeCalled***@voip.dt.ept.lu>;tag=gK08945167  

74485   Call-ID: 222a0723-05a0-4dc5-97eb-dabc20c3d609   

74486   CSeq: 12695 INVITE  

74487   Contact: <sip:***numberToBeCalled***@213.166.61.116:5060>   

74488   Allow: INVITE,ACK,CANCEL,BYE,REGISTER,REFER,INFO,SUBSCRIBE,NOTIFY,UPDATE,OPTIONS,MESSAGE,PUBLISH    

74489   P-Asserted-Identity: <sip:213.166.61.116:5060>  

74490   Privacy: none   

74491   Accept: application/dtmf-relay, application/media_control+xml, application/sdp, multipart/mixed 

74492   Require: timer  

74493   Supported: timer,replaces   

74494   Session-Expires: 1800;refresher=uac 

74495   Content-Length: 231 

74496   Content-Disposition: session; handling=required 

74497   Content-Type: application/sdp   

74498       

74499   v=0 

74500   o=- 578898 957528 IN IP4 213.166.61.118 

74501   s=SIP Media Capabilities    

74502   c=IN IP4 213.166.61.118 

74503   t=0 0   

74504   m=audio 45112 RTP/AVP 8 101 

74505   a=ptime:20  

74506   a=rtpmap:8 PCMA/8000    

74507   a=rtpmap:101 telephone-event/8000   

74508   a=fmtp:101 0-15 

74509   a=sendrecv  

74510       

74511   [2021-12-20 12:41:24] VERBOSE[1864] res_pjsip_logger.c: <--- Transmitting SIP request (420 bytes) to TCP:213.166.61.116:5060 --->   

74512   ACK sip:***numberToBeCalled***@213.166.61.116:5060 SIP/2.0  

74513   Via: SIP/2.0/TCP ***myExternalIP***:5060;rport;branch=z9hG4bKPje1a86325-97bd-43f3-87e3-520f0b41333a;alias   

74514   From: <sip:***myPhoneNumber***@voip.dt.ept.lu>;tag=0b0d4df6-7240-4d90-9242-7d6c2fad251d 

74515   To: <sip:***numberToBeCalled***@voip.dt.ept.lu>;tag=gK08945167  

74516   Call-ID: 222a0723-05a0-4dc5-97eb-dabc20c3d609   

74517   CSeq: 12695 ACK 

74518   Max-Forwards: 70    

74519   User-Agent: FPBX-15.0.17.64(16.17.0)    

74520   Content-Length: 0   

74521       

74522       

74523   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] app_dial.c: PJSIP/***myPhoneNumber***-00000026 answered PJSIP/2-00000025    

74524   [2021-12-20 12:41:24] VERBOSE[16464] res_pjsip_logger.c: <--- Transmitting SIP response (968 bytes) to UDP:***myPCIP***:5060 --->   

74525   SIP/2.0 200 OK  

74526   Via: SIP/2.0/UDP ***myPCIP***:5060;rport=5060;received=***myPCIP***;branch=z9hG4bK-524287-1---b9620f3096d03d35  

74527   Call-ID: JKVcjKdhlvEjcZKdG5QHKA..   

74528   From: "Home" <sip:2@***myFreePBXIP***>;tag=1f64d47f 

74529   To: <sip:32***numberToBeCalled***@***myFreePBXIP***>;tag=78c212e6-5b05-4f2d-bb3d-608a0dddb131   

74530   CSeq: 2 INVITE  

74531   Server: FPBX-15.0.17.64(16.17.0)    

74532   Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER   

74533   Contact: <sip:***myFreePBXIP***:5060>   

74534   Supported: 100rel, timer, replaces, norefersub  

74535   P-Asserted-Identity: "CID:***myPhoneNumber***" <sip:32***numberToBeCalled***@***myFreePBXIP***> 

74536   Content-Type: application/sdp   

74537   Content-Length: 301 

74538       

74539   v=0 

74540   o=- 321892619 3 IN IP4 ***myFreePBXIP***    

74541   s=Asterisk  

74542   c=IN IP4 ***myFreePBXIP***  

74543   t=0 0   

74544   m=audio 7082 RTP/AVP 8 0 3 9 101    

74545   a=rtpmap:8 PCMA/8000    

74546   a=rtpmap:0 PCMU/8000    

74547   a=rtpmap:3 GSM/8000 

74548   a=rtpmap:9 G722/8000    

74549   a=rtpmap:101 telephone-event/8000   

74550   a=fmtp:101 0-16 

74551   a=ptime:20  

74552   a=maxptime:150  

74553   a=sendrecv  

74554       

74555   [2021-12-20 12:41:24] VERBOSE[5553][C-00000016] bridge_channel.c: Channel PJSIP/***myPhoneNumber***-00000026 joined 'simple_bridge' basic-bridge <05e639a4-9032-45bd-b025-080360376aa4> 

74556   [2021-12-20 12:41:24] VERBOSE[5531][C-00000016] bridge_channel.c: Channel PJSIP/2-00000025 joined 'simple_bridge' basic-bridge <05e639a4-9032-45bd-b025-080360376aa4>   

74557   [2021-12-20 12:41:24] VERBOSE[3237] res_pjsip_logger.c: <--- Received SIP request (424 bytes) from UDP:***myPCIP***:5060 --->   

74558   ACK sip:***myFreePBXIP***:5060 SIP/2.0  

74559   Via: SIP/2.0/UDP ***myPCIP***:5060;branch=z9hG4bK-524287-1---8b1f21e97dec1c6d;rport 

74560   Max-Forwards: 70    

74561   Contact: <sip:2@***myPCIP***:5060;transport=UDP>    

74562   To: <sip:32***numberToBeCalled***@***myFreePBXIP***>;tag=78c212e6-5b05-4f2d-bb3d-608a0dddb131   

74563   From: "Home" <sip:2@***myFreePBXIP***>;tag=1f64d47f 

74564   Call-ID: JKVcjKdhlvEjcZKdG5QHKA..   

74565   CSeq: 2 ACK 

74566   User-Agent: Z 5.5.8 v2.10.17.2  

74567   Content-Length: 0
4

Do you know a better way to output FreePBX config then screenshots ? Will post them if it helps.

5

dump them to a pastebin.

6

Your log shows a successful call!

7

Unfortunately it is not successfull, the provider returns a voice message that the number is not available although the same number is sent to it. I cannot understand the difference between the two logs which provokes this. The packets seem the same to me, I fear they could block the user agent Asterisk ? Do you think this is a possibility ?

8

It’s unlikely that they would block Asterisk. The only reason I can think of for doing that would be because they were blocking all PABXes, However, although there are a lot of people trying to use services that appear to be designed only for use with phones, I’ve never heard of one actually refusing to accept a call.

Noting the “residential” in the domain name, I suppose they could be inferring that anyone using a PABX was a business, although, with Asterisk, that is not always true.

We would need the trace for the working case to be able to guess at any technical reason, although, given that they have set up a valid, answered, call, in order to play the failure as in band normal media, I think the only technical problem would be a malformed number in the user part of the request URI.

9

This topic was automatically closed 31 days after the last reply. New replies are no longer allowed.