DTMF messages when endpoints unreachable - Asterisk 13 with PJSIP

lmoraes · February 16, 2021, 11:54am

I have an Asterisk server version 13 - PJSIP and Realtime (ARA) in a Ubuntu 18 OS running over the Internet with clients behind a NAT that is losting connection for many endpoints(becoming unreachable) in the same time (not all endpoints), when it happens the CLI logged the messages bellow about DTMF.

I would like to know if theses messages could be any relation with the issue informed, and if yes what does it means?

[Feb 15 11:41:05] DTMF[14306][C-0000d6c8] channel.c: DTMF begin '1' received on PJSIP/GTIN-GTGI2-0001fe59
[Feb 15 11:41:05] DTMF[14306][C-0000d6c8] channel.c: DTMF begin ignored '1' on PJSIP/GTIN-GTGI2-0001fe59
[Feb 15 11:41:05] DTMF[14306][C-0000d6c8] channel.c: DTMF end '1' received on PJSIP/GTIN-GTGI2-0001fe59, duration 163 ms
[Feb 15 11:41:05] DTMF[14306][C-0000d6c8] channel.c: DTMF end passthrough '1' on PJSIP/GTIN-GTGI2-0001fe59
[Feb 15 11:41:07] NOTICE[2300] res_pjsip/pjsip_distributor.c: Request 'INVITE' from '<sip:1x23y4@55.255.55.55>' failed for '23.146.241.14:62161' (callid: 1409776235-910214409-1575796180) - No matching endpoint found
[Feb 15 11:41:21] DTMF[14339][C-0000d6c9] channel.c: DTMF begin '1' received on PJSIP/algar-sbc-fac-0001fe5d
[Feb 15 11:41:21] DTMF[14339][C-0000d6c9] channel.c: DTMF begin ignored '1' on PJSIP/algar-sbc-fac-0001fe5d
[Feb 15 11:41:21] DTMF[14339][C-0000d6c9] channel.c: DTMF end '1' received on PJSIP/algar-sbc-fac-0001fe5d, duration 91 ms
[Feb 15 11:41:21] DTMF[14339][C-0000d6c9] channel.c: DTMF end passthrough '1' on PJSIP/algar-sbc-fac-0001fe5d
[Feb 15 11:42:05] NOTICE[25994] res_pjsip/pjsip_distributor.c: Request 'INVITE' from '<sip:230115423316233:5060@55.255.55.55>' failed for '84.247.51.238:63659' (callid: 1037957985-1921835950-613754545) - No matching endpoint found
[Feb 15 11:42:06] WARNING[2300] res_pjsip_pubsub.c: No registered publish handler for event presence
[Feb 15 11:42:19] NOTICE[4759] res_pjsip/pjsip_distributor.c: Request 'INVITE' from '<sip:1x234y@55.255.55.55>' failed for '23.146.241.14:54952' (callid: 1196355053-387961327-508409210) - No matching endpoint found
[Feb 15 11:42:43] WARNING[23562] res_pjsip_pubsub.c: No registered publish handler for event presence
[Feb 15 11:42:49] WARNING[14511][C-0000d6d0] chan_iax2.c: Resyncing the jb. last_delay 0, this delay -7140677, threshold 1000, new offset 7140677
[Feb 15 11:42:52] NOTICE[31173] res_pjsip/pjsip_distributor.c: Request 'OPTIONS' from '"asterisk" <sip:asterisk@10.55.64.41>' failed for '200.187.179.34:5060' (callid: 6359992d426f907376d22e264817c1f9@10.55.64.41:5060) - No matching endpoint found
[Feb 15 11:43:01] NOTICE[7939] res_pjsip/pjsip_distributor.c: Request 'REGISTER' from '<sip:21015020@sip.xpto123.com>' failed for '168.121.180.17:50832' (callid: 1140973666-45652-1@BA.CFC.BG.BIE) - Failed to authenticate
[Feb 15 11:43:14] NOTICE[22594] res_pjsip/pjsip_distributor.c: Request 'INVITE' from '<sip:1x234y@55.255.55.55>' failed for '23.146.241.14:63805' (callid: 242412101-1518671616-215310339) - No matching endpoint found
[Feb 15 11:43:15] DTMF[14533][C-0000d6d2] channel.c: DTMF begin '1' received on PJSIP/algar-sbc-spo-0001fe81
[Feb 15 11:43:15] DTMF[14533][C-0000d6d2] channel.c: DTMF begin ignored '1' on PJSIP/algar-sbc-spo-0001fe81
[Feb 15 11:43:15] DTMF[14533][C-0000d6d2] channel.c: DTMF end '1' received on PJSIP/algar-sbc-spo-0001fe81, duration 100 ms
[Feb 15 11:43:15] DTMF[14533][C-0000d6d2] channel.c: DTMF end passthrough '1' on PJSIP/algar-sbc-spo-0001fe81
[Feb 15 11:43:16] NOTICE[25456] res_pjsip/pjsip_distributor.c: Request 'INVITE' from '"201" <sip:201@55.255.55.55>' failed for '37.49.230.11:5071' (callid: d9b15ebb5e96ebb6d205cc4fa05bdec9) - No matching endpoint found
[Feb 15 11:43:33] WARNING[14576][C-0000d6d5] chan_iax2.c: Resyncing the jb. last_delay 0, this delay -447110756, threshold 1000, new offset 447110756
[Feb 15 11:43:59] WARNING[14653][C-0000d6d6] chan_iax2.c: Resyncing the jb. last_delay 0, this delay -216481900, threshold 1000, new offset 216481900
[Feb 15 11:44:20] NOTICE[22446] res_pjsip/pjsip_distributor.c: Request 'INVITE' from '<sip:1x234y@55.255.55.55>' failed for '23.146.241.14:50308' (callid: 40346028-1842829418-229888639) - No matching endpoint found
[Feb 15 11:44:25] DTMF[14689][C-0000d6d8] channel.c: DTMF begin '1' received on PJSIP/algar-sbc-fac-0001fe95
[Feb 15 11:44:25] DTMF[14689][C-0000d6d8] channel.c: DTMF begin passthrough '1' on PJSIP/algar-sbc-fac-0001fe95
[Feb 15 11:44:25] DTMF[14689][C-0000d6d8] channel.c: DTMF end '1' received on PJSIP/algar-sbc-fac-0001fe95, duration 91 ms
[Feb 15 11:44:25] DTMF[14689][C-0000d6d8] channel.c: DTMF end accepted with begin '1' on PJSIP/algar-sbc-fac-0001fe95
[Feb 15 11:44:25] DTMF[14689][C-0000d6d8] channel.c: DTMF end passthrough '1' on PJSIP/algar-sbc-fac-0001fe95
[Feb 15 11:44:28] DTMF[14677][C-0000d6d7] channel.c: DTMF begin '1' received on PJSIP/GTIN-GTGI2-0001fe94
[Feb 15 11:44:28] DTMF[14677][C-0000d6d7] channel.c: DTMF begin ignored '1' on PJSIP/GTIN-GTGI2-0001fe94
[Feb 15 11:44:28] DTMF[14677][C-0000d6d7] channel.c: DTMF end '1' received on PJSIP/GTIN-GTGI2-0001fe94, duration 157 ms
[Feb 15 11:44:28] DTMF[14677][C-0000d6d7] channel.c: DTMF end passthrough '1' on PJSIP/GTIN-GTGI2-0001fe94
[Feb 15 11:44:34] WARNING[22546] res_pjsip_pubsub.c: No registered publish handler for event presence
[Feb 15 11:44:52] NOTICE[11286] res_pjsip/pjsip_distributor.c: Request 'OPTIONS' from '"asterisk" <sip:asterisk@10.55.64.41>' failed for '200.187.179.34:5060' (callid: 5f0ccd2b41109d25775c6d630924a1f3@10.55.64.41:5060) - No matching endpoint found
[Feb 15 11:45:01] DTMF[14764][C-0000d6dc] channel.c: DTMF begin '1' received on PJSIP/algar-sbc-spo-0001fe9f
[Feb 15 11:45:01] DTMF[14764][C-0000d6dc] channel.c: DTMF begin ignored '1' on PJSIP/algar-sbc-spo-0001fe9f
[Feb 15 11:45:02] DTMF[14764][C-0000d6dc] channel.c: DTMF end '1' received on PJSIP/algar-sbc-spo-0001fe9f, duration 101 ms
[Feb 15 11:45:02] DTMF[14764][C-0000d6dc] channel.c: DTMF end passthrough '1' on PJSIP/algar-sbc-spo-0001fe9f
[Feb 15 11:45:22] DTMF[14677][C-0000d6d7] channel.c: DTMF begin '2' received on PJSIP/GTIN-GTGI2-0001fe94
[Feb 15 11:45:22] DTMF[14677][C-0000d6d7] channel.c: DTMF begin passthrough '2' on PJSIP/GTIN-GTGI2-0001fe94
[Feb 15 11:45:23] DTMF[14677][C-0000d6d7] channel.c: DTMF end '2' received on PJSIP/GTIN-GTGI2-0001fe94, duration 357 ms
[Feb 15 11:45:23] DTMF[14677][C-0000d6d7] channel.c: DTMF end accepted with begin '2' on PJSIP/GTIN-GTGI2-0001fe94
[Feb 15 11:45:23] DTMF[14677][C-0000d6d7] channel.c: DTMF end passthrough '2' on PJSIP/GTIN-GTGI2-0001fe94
[Feb 15 11:45:24] NOTICE[20946] res_pjsip/pjsip_distributor.c: Request 'INVITE' from '<sip:12xy34@55.255.55.55>' failed for '23.146.241.14:61841' (callid: 2077056407-1944309041-1144258109) - No matching endpoint found
[Feb 15 11:45:42] WARNING[7253] res_pjsip_pubsub.c: No registered publish handler for event presence
[Feb 15 11:46:15] NOTICE[7200] res_pjsip/pjsip_distributor.c: Request 'INVITE' from '<sip:12xy34@55.255.55.55>' failed for '23.146.241.14:65500' (callid: 108544743-303322277-280526780) - No matching endpoint found
[Feb 15 11:46:38] DTMF[14986][C-0000d6e1] channel.c: DTMF begin '8' received on PJSIP/GTIN-GTGI2-0001feb1
[Feb 15 11:46:38] DTMF[14986][C-0000d6e1] channel.c: DTMF begin passthrough '8' on PJSIP/GTIN-GTGI2-0001feb1
[Feb 15 11:46:38] DTMF[14986][C-0000d6e1] channel.c: DTMF end '8' received on PJSIP/GTIN-GTGI2-0001feb1, duration 28 ms
[Feb 15 11:46:38] DTMF[14986][C-0000d6e1] channel.c: DTMF end accepted with begin '8' on PJSIP/GTIN-GTGI2-0001feb1
[Feb 15 11:46:38] DTMF[14986][C-0000d6e1] channel.c: DTMF end '8' detected to have actual duration 40 on the wire, emulation will be triggered on PJSIP/GTIN-GTGI2-0001feb1
[Feb 15 11:46:38] DTMF[14986][C-0000d6e1] channel.c: DTMF end '8' has duration 40 but want minimum 80, emulating on PJSIP/GTIN-GTGI2-0001feb1
[Feb 15 11:46:38] DTMF[14986][C-0000d6e1] channel.c: DTMF end emulation of '8' queued on PJSIP/GTIN-GTGI2-0001feb1
[Feb 15 11:46:45] DTMF[14769][C-0000d6db] channel.c: DTMF end '9' received on PJSIP/21032005-0001fe9e, duration 250 ms
[Feb 15 11:46:45] DTMF[14769][C-0000d6db] channel.c: DTMF begin emulation of '9' with duration 250 queued on PJSIP/21032005-0001fe9e
[Feb 15 11:46:45] DTMF[14769][C-0000d6db] channel.c: DTMF end emulation of '9' queued on PJSIP/21032005-0001fe9e
[Feb 15 11:46:52] NOTICE[31725] res_pjsip/pjsip_distributor.c: Request 'OPTIONS' from '"asterisk" <sip:asterisk@10.55.64.41>' failed for '200.187.179.34:5060' (callid: 361c727474f62265476469b012ed2833@10.55.64.41:5060) - No matching endpoint found
[Feb 15 11:46:54] WARNING[15225][C-0000d6e7] pbx.c: Channel 'PJSIP/21015007-0001fec0' sent to invalid extension but no invalid handler: context,exten,priority=error,No results error. Possibly non existing extension,1
[Feb 15 11:47:06] WARNING[7641] res_pjsip_pubsub.c: No registered publish handler for event presence

david551 · February 16, 2021, 12:59pm

The most common option for DTMF involves sending it in the media stream. Unreachable is based on events affecting the signalling stream. In the general case (direct media) signalling and media may be coming from different places (typically signalling relayed, and media direct), so it is quite possible to lose signalling connectivity without losing media connectivity.

If you have NAT or firewalls, dynamic rules for signalling and media streams will not be correlated .

Signalling connectivity is tested by polling, and loss might be recorded as the result of a short burst of packets, but require some time for good connectivity to be confirmed.

system · March 18, 2021, 1:00pm

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