Extensions not reachable for a period and then they are

rnrstar · January 2, 2020, 5:26pm

We are running FreePBX 14.0.13.23
Extensions are using pjsip.

Intermittently our users will stop getting calls delivered from their respective queues. Calls will wait in the queue even though agents think they are available for calls. When I call their extension directly it indicates that they are unavailable.

We are running FOP2 2.32.21 and this failure becomes noticeable when we look at the buttons for each extension and they are showing as a shaded green like they are unregistered. I’ve tried to do restart FOP2 (service fop2 restart) although I don’t think FOP2 is the issue and is only exposing it.

I’ve also tried an fwconsole restart and that too doesn’t seem to do anything. Eventually, the phones will register as I can see the registration traffic and then they start receiving calls.

Any suggestions as to what to look for and how I might further troubleshoot this?

billsimon · January 2, 2020, 5:29pm

Restarting the PBX won’t help, as it’s a problem with your network. Something prevents the phones from remaining in contact with the PBX.

rnrstar · January 2, 2020, 5:47pm

[2020-01-02 05:40:27] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 1277 is now Unreachable
[2020-01-02 05:40:27] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 1277/sip:[email protected]:58351;rinstance=e40db82a009e5903 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 05:55:49] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 1304 is now Unreachable
[2020-01-02 05:58:29] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 1228 is now Unreachable
[2020-01-02 05:58:58] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 1250 is now Unreachable
[2020-01-02 05:59:28] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 1236 is now Unreachable
[2020-01-02 06:00:30] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 1251 is now Unreachable
[2020-01-02 06:01:03] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 1323 is now Unreachable
[2020-01-02 07:51:35] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 1301 is now Unreachable
[2020-01-02 07:51:35] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 1301/sip:[email protected]:60171;rinstance=1134000a94c91e46 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:36] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 251 is now Unreachable
[2020-01-02 07:51:36] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 251/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:39] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 202 is now Unreachable
[2020-01-02 07:51:39] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 202/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:40] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 229 is now Unreachable
[2020-01-02 07:51:40] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 229/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:41] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 221 is now Unreachable
[2020-01-02 07:51:41] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 221/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:42] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 1224 is now Unreachable
[2020-01-02 07:51:42] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 1224/sip:[email protected]:53244;rinstance=faacd0f7215102be is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:44] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 206 is now Unreachable
[2020-01-02 07:51:44] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 206/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:46] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 1289 is now Unreachable
[2020-01-02 07:51:46] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 1289/sip:[email protected]:62644;rinstance=833cddbc8b236300 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:47] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 209 is now Unreachable
[2020-01-02 07:51:47] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 209/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:48] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 222 is now Unreachable
[2020-01-02 07:51:48] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 222/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:49] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 1304 is now Unreachable
[2020-01-02 07:51:49] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 1304/sip:[email protected]:57342;rinstance=267b6f4515a25e41 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:51] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 218 is now Unreachable
[2020-01-02 07:51:51] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 218/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:52] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 1326 is now Unreachable
[2020-01-02 07:51:52] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 1326/sip:[email protected]:51348;rinstance=062e9b4940988183 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:54] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 207 is now Unreachable
[2020-01-02 07:51:54] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 207/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:56] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 1222 is now Unreachable
[2020-01-02 07:51:56] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 1222/sip:[email protected]:55890;rinstance=a8e6a22d2da8f3c7 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:57] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 208 is now Unreachable
[2020-01-02 07:51:57] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 208/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:58] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 1284 is now Unreachable
[2020-01-02 07:51:58] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 1284/sip:[email protected]:58280;rinstance=f6f20080c7e88dbc is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:58] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 1250 is now Unreachable
[2020-01-02 07:51:58] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 1250/sip:[email protected]:56345;rinstance=a3c155d69dfbb804 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:51:58] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 212 is now Unreachable
[2020-01-02 07:51:58] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 212/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:00] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 1234 is now Unreachable
[2020-01-02 07:52:00] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 1234/sip:[email protected]:53616;rinstance=8fad3afe0ad3eaf0 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:01] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 223 is now Unreachable
[2020-01-02 07:52:01] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 223/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:02] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 225 is now Unreachable
[2020-01-02 07:52:02] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 225/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:03] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 1323 is now Unreachable
[2020-01-02 07:52:03] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 1323/sip:[email protected]:54588;rinstance=58404429f20b652b is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:05] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 1249 is now Unreachable
[2020-01-02 07:52:05] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 1249/sip:[email protected]:58022;rinstance=b5b5a3f10a20ef53 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:05] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 211 is now Unreachable
[2020-01-02 07:52:05] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 211/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:07] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Unreachable
[2020-01-02 07:52:07] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:07] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 215 is now Unreachable
[2020-01-02 07:52:07] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 215/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:07] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 231 is now Unreachable
[2020-01-02 07:52:07] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 231/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:11] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 204 is now Unreachable
[2020-01-02 07:52:11] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 204/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:14] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 232 is now Unreachable
[2020-01-02 07:52:14] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 232/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:16] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 224 is now Unreachable
[2020-01-02 07:52:16] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 224/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:17] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 1275 is now Unreachable
[2020-01-02 07:52:17] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 1275/sip:[email protected]:63978;rinstance=d36b599774a7c6b1 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:18] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 1308 is now Unreachable
[2020-01-02 07:52:18] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 1308/sip:[email protected]:60159;rinstance=867fd8c1ae99c99c is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:19] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 227 is now Unreachable
[2020-01-02 07:52:19] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 227/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:20] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 233 is now Unreachable
[2020-01-02 07:52:20] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 233/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:20] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 216 is now Unreachable
[2020-01-02 07:52:20] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 216/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:20] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 243 is now Unreachable
[2020-01-02 07:52:20] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 243/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:24] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 1201 is now Unreachable
[2020-01-02 07:52:24] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 1201/sip:[email protected]:63790;rinstance=ae75f37921be5cc2 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:26] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 200 is now Unreachable
[2020-01-02 07:52:26] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 200/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:28] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 234 is now Unreachable
[2020-01-02 07:52:28] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 234/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:28] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 1236 is now Unreachable
[2020-01-02 07:52:28] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 1236/sip:[email protected]:56762;rinstance=49736f85c40cd33c is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:29] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 1228 is now Unreachable
[2020-01-02 07:52:29] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 1228/sip:[email protected]:65531;rinstance=e86305374bd642d1 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:29] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 1328 is now Unreachable
[2020-01-02 07:52:29] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 1328/sip:[email protected]:63649;rinstance=88bf22e66ce47dd4 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:29] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 219 is now Unreachable
[2020-01-02 07:52:29] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 219/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:29] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 205 is now Unreachable
[2020-01-02 07:52:29] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 205/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:30] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 1251 is now Unreachable
[2020-01-02 07:52:30] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 1251/sip:[email protected]:62327;rinstance=83a911b11bd7b23b is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:30] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 201 is now Unreachable
[2020-01-02 07:52:30] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 201/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:31] VERBOSE[28090] res_pjsip/pjsip_configuration.c: Endpoint 226 is now Unreachable
[2020-01-02 07:52:31] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 226/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:31] VERBOSE[27786] res_pjsip/pjsip_configuration.c: Endpoint 1260 is now Unreachable
[2020-01-02 07:52:31] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 1260/sip:[email protected]:55854;rinstance=3ce202ab2997af5d is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:52:34] VERBOSE[13479] res_pjsip/pjsip_configuration.c: Endpoint 217 is now Unreachable
[2020-01-02 07:52:34] VERBOSE[13479] res_pjsip/pjsip_options.c: Contact 217/sip:[email protected]:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:54:25] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 1323/sip:[email protected]:50864;rinstance=1253aca4695a1463 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:54:25] VERBOSE[5438] res_pjsip/pjsip_options.c: Contact 1323/sip:[email protected]:50864;rinstance=1253aca4695a1463 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:57:48] VERBOSE[5438] res_pjsip/pjsip_options.c: Contact 1251/sip:[email protected]:57556;rinstance=61c5e7d8b7c69eb1 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:57:48] VERBOSE[5438] res_pjsip/pjsip_options.c: Contact 1251/sip:[email protected]:57556;rinstance=61c5e7d8b7c69eb1 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 08:01:51] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 1258/sip:[email protected]:51387;rinstance=8bb02b9f4ea35665 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 08:01:51] VERBOSE[27786] res_pjsip/pjsip_options.c: Contact 1258/sip:[email protected]:51387;rinstance=8bb02b9f4ea35665 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 08:33:19] VERBOSE[17481] res_pjsip/pjsip_configuration.c: Endpoint 228 is now Unreachable
[2020-01-02 08:33:19] VERBOSE[17481] res_pjsip/pjsip_options.c: Contact 228/sip:[email protected]:5060 is now Unreachable.  RTT: 0.000 msec
[root@fonefactory-b asterisk]# grep 'VERBOSE\[5438\]' full
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [1224@from-queue:1] Set("Local/1224@from-queue-00004056;2", "QAGENT=1224") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [1224@from-queue:2] Set("Local/1224@from-queue-00004056;2", "__FROMQ=true") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [1224@from-queue:3] GotoIf("Local/1224@from-queue-00004056;2", "0?hangup") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [1224@from-queue:4] GotoIf("Local/1224@from-queue-00004056;2", "1?100,1:hangup") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx_builtins.c: Goto (from-queue,100,1)
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [100@from-queue:1] Goto("Local/1224@from-queue-00004056;2", "from-internal,1224,1") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx_builtins.c: Goto (from-internal,1224,1)
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [1224@from-internal:1] GotoIf("Local/1224@from-queue-00004056;2", "1?ext-local,1224,1:followme-check,1224,1") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx_builtins.c: Goto (ext-local,1224,1)
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [1224@ext-local:1] Set("Local/1224@from-queue-00004056;2", "__RINGTIMER=15") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [1224@ext-local:2] Macro("Local/1224@from-queue-00004056;2", "exten-vm,1224,1224,0,0,0") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-exten-vm:1] Macro("Local/1224@from-queue-00004056;2", "user-callerid,") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:1] Set("Local/1224@from-queue-00004056;2", "TOUCH_MONITOR=1577978162.35651") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:2] Set("Local/1224@from-queue-00004056;2", "AMPUSER=1250") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("Local/1224@from-queue-00004056;2", "1?report") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx_builtins.c: Goto (macro-user-callerid,s,17)
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:17] NoOp("Local/1224@from-queue-00004056;2", "Macro Depth is 2") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:18] GotoIf("Local/1224@from-queue-00004056;2", "1?report2:macroerror") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx_builtins.c: Goto (macro-user-callerid,s,19)
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:19] GotoIf("Local/1224@from-queue-00004056;2", "0?continue") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:20] ExecIf("Local/1224@from-queue-00004056;2", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:21] Set("Local/1224@from-queue-00004056;2", "__TTL=62") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:22] GotoIf("Local/1224@from-queue-00004056;2", "1?continue") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx_builtins.c: Goto (macro-user-callerid,s,38)
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:38] Set("Local/1224@from-queue-00004056;2", "CALLERID(number)=1250") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:39] Set("Local/1224@from-queue-00004056;2", "CALLERID(name)=Faatimah Ali") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:40] GotoIf("Local/1224@from-queue-00004056;2", "0?cnum") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:41] Set("Local/1224@from-queue-00004056;2", "CDR(cnam)=Faatimah Ali") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:42] Set("Local/1224@from-queue-00004056;2", "CDR(cnum)=1250") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-user-callerid:43] Set("Local/1224@from-queue-00004056;2", "CHANNEL(language)=en") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-exten-vm:2] Set("Local/1224@from-queue-00004056;2", "RingGroupMethod=none") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-exten-vm:3] Set("Local/1224@from-queue-00004056;2", "__EXTTOCALL=1224") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-exten-vm:4] Set("Local/1224@from-queue-00004056;2", "__PICKUPMARK=1224") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-exten-vm:5] Set("Local/1224@from-queue-00004056;2", "RT=15") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@macro-exten-vm:6] Gosub("Local/1224@from-queue-00004056;2", "sub-record-check,s,1(exten,1224,dontcare)") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@sub-record-check:1] GotoIf("Local/1224@from-queue-00004056;2", "4?initialized") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx_builtins.c: Goto (sub-record-check,s,10)
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@sub-record-check:10] NoOp("Local/1224@from-queue-00004056;2", "Recordings initialized") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@sub-record-check:11] ExecIf("Local/1224@from-queue-00004056;2", "0?Set(ARG3=dontcare)") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@sub-record-check:12] Set("Local/1224@from-queue-00004056;2", "REC_POLICY_MODE_SAVE=NO") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@sub-record-check:13] ExecIf("Local/1224@from-queue-00004056;2", "0?Set(REC_STATUS=NO)") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@sub-record-check:14] GotoIf("Local/1224@from-queue-00004056;2", "5?checkaction") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx_builtins.c: Goto (sub-record-check,s,17)
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [s@sub-record-check:17] GotoIf("Local/1224@from-queue-00004056;2", "1?sub-record-check,exten,1") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx_builtins.c: Goto (sub-record-check,exten,1)
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [exten@sub-record-check:1] NoOp("Local/1224@from-queue-00004056;2", "Exten Recording Check between 1250 and 1224") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [exten@sub-record-check:2] Set("Local/1224@from-queue-00004056;2", "CALLTYPE=internal") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [exten@sub-record-check:3] ExecIf("Local/1224@from-queue-00004056;2", "0?Set(CALLTYPE=)") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [exten@sub-record-check:4] Set("Local/1224@from-queue-00004056;2", "CALLEE=dontcare") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [exten@sub-record-check:5] ExecIf("Local/1224@from-queue-00004056;2", "0?Set(CALLEE=dontcare)") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [exten@sub-record-check:6] GotoIf("Local/1224@from-queue-00004056;2", "0?callee") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx.c: Executing [exten@sub-record-check:7] GotoIf("Local/1224@from-queue-00004056;2", "1?caller") in new stack
[2020-01-02 07:16:02] VERBOSE[5438][C-0000056e] pbx_builtins.c: Goto (sub-record-check,exten,13)

rnrstar · January 2, 2020, 5:47pm

Any suggestions on what that might be?

billsimon · January 2, 2020, 5:51pm

Could you describe your network topology a bit? Where are the phones and the PBX? I am guessing there is routing going on here unless you’re using a big flat network 10.0.0.0/8.

rnrstar · January 2, 2020, 5:59pm

Our server is at 10.0.1.26. Most of the extensions are on 10.0.121.0, 10.0.131.0, 10.0.141.0, 10.0.151.0.

We have two fortinet routers configured in HA mode behind a Bigleaf SDWAN. We have about six Cisco SG300 switches internally. We have a core switch that then spokes out to other switches for the various groups. We are using Bria 5 softphones and Yealink T-22 SIP phones. I haven’t noticed yet if it affects the Yealink phones as it does the Bria softphones.

dicko · January 2, 2020, 6:03pm

You need to better describe your network, from bash the output of

ip address

and

ip route

will help

rnrstar · January 2, 2020, 6:05pm

Here you go:

Output from ip address:

1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host
       valid_lft forever preferred_lft forever
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000
    link/ether 00:90:28:00:c1:8b brd ff:ff:ff:ff:ff:ff
    inet 10.0.1.26/24 brd 10.0.1.255 scope global eth0
       valid_lft forever preferred_lft forever
    inet6 fe80::290:28ff:fe00:c18b/64 scope link
       valid_lft forever preferred_lft forever
3: eth1: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 00:90:28:00:c1:8c brd ff:ff:ff:ff:ff:ff
4: eth2: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 00:90:28:00:c1:8d brd ff:ff:ff:ff:ff:ff
5: eth3: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 00:90:28:00:c1:8e brd ff:ff:ff:ff:ff:ff
6: eth4: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 00:90:28:00:c1:8f brd ff:ff:ff:ff:ff:ff
7: eth5: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 00:90:28:00:c1:90 brd ff:ff:ff:ff:ff:ff

Output from ip route:
default via 10.0.1.1 dev eth0
10.0.1.0/24 dev eth0 proto kernel scope link src 10.0.1.26
169.254.0.0/16 dev eth0 scope link metric 1002

dicko · January 2, 2020, 6:10pm

Then your network is 10.0.1.0/24 ( the netmask is 255.255.255.0) and the gateway is thePBX server at 10.0.1.26

All your phones will need to be something like 10.0.1.(2-255) to be in the scope of the network

ediot: oops, sorry

billsimon · January 2, 2020, 6:32pm

Pretty sure that’s what the routers are for @dicko

This would be very helpful behavior to observe.

Do your routers also implement filters/firewall between the phones and PBX? Could there be a timeout happening?

The Yealinks might be sending keepalive packets while the Bria phones are not.

A pcap (at the router or one of the switches) could reveal more.

rnrstar · January 2, 2020, 6:37pm

I have “Local Networks” defined for each subnet in SIP Settings.

10.0.151.0/24, etc.

This is something that has been working for quite some time but only in the last week have we seen this issue.

billsimon · January 2, 2020, 6:39pm

Was there a Windows update or software update for Bria?

rnrstar · January 2, 2020, 9:42pm

Looks like the pjsip driver was the issue. Apparently with the setting “Allow Transports Reload” set to “yes” there is a known issue that when one applies changes, all the pjsip registrations will be lost. After thinking about it sure enough the failure occurred when we were applying changes after changing settings.

system · January 9, 2020, 9:42pm

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