Extensions not reachable for a period and then they are


(Todd Schacherl) #1

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?


#2

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.


(Todd Schacherl) #3
[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:1277@10.0.121.65: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:1301@10.0.141.21: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:251@10.0.151.66: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:202@10.0.1.88: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:229@10.0.151.110: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:221@10.0.151.96: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:1224@10.0.141.38: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:206@10.0.151.104: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:1289@10.0.121.37: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:209@10.0.1.128: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:222@10.0.1.120: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:1304@10.0.141.26: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:218@10.0.151.111: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:1326@10.0.141.31: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:207@10.0.151.81: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:1222@10.0.121.29: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:208@10.0.151.97: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:1284@10.0.121.60: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:1250@10.0.121.22: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:212@10.0.151.83: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:1234@10.0.131.21: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:223@10.0.1.87: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:225@10.0.151.107: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:1323@10.0.141.30: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:1249@10.0.131.28: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:211@10.0.151.87: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:110@10.0.1.94: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:215@10.0.151.105: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:231@10.0.161.26: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:204@10.0.151.103: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:232@10.0.161.21: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:224@10.0.151.116: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:1275@10.0.141.35: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:1308@10.0.141.32: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:227@10.0.1.95: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:233@10.0.161.23: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:216@10.0.1.92: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:243@10.0.151.70: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:1201@10.0.121.21: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:200@10.0.1.98: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:234@10.0.151.84: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:1236@10.0.131.33: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:1228@10.0.141.20: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:1328@10.0.141.34: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:219@10.0.151.86: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:205@10.0.1.114: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:1251@10.0.121.41: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:201@10.0.1.138: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:226@10.0.151.85: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:1260@10.0.121.67: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:217@10.0.151.106:5062 is now Unreachable.  RTT: 0.000 msec
[2020-01-02 07:54:25] VERBOSE[28090] res_pjsip/pjsip_options.c: Contact 1323/sip:1323@10.0.141.30: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:1323@10.0.141.30: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:1251@10.0.121.41: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:1251@10.0.121.41: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:1258@10.0.121.48: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:1258@10.0.121.48: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:228@10.0.151.72: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)

(Todd Schacherl) #4

Any suggestions on what that might be?


#5

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.


(Todd Schacherl) #6

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.


#7

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

ip address

and

ip route

will help


(Todd Schacherl) #8

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


#9

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 :slight_smile:


#10

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

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.


(Todd Schacherl) #11

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.


#12

Was there a Windows update or software update for Bria?


(Todd Schacherl) #13

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) closed #14

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