Fwconsole restart breaks BLFs

Background
Yesterday, I transferred my PBX from one hardware to another and upgraded it.

On the old box, I was using:
FreePBX 12.0.76.4
6.12.65-32

On the replacement box, I installed 6.12.65-30, patched it up to -32 and then did a restore from a backup of the above box.

I then upgraded the replacement box using the upgradescripts

The replacement box is now at
FreePBX 13.0.190.7
10.13.66-17

I now have a problem where “fwconsole restart” borks up my BLFs. If I do an fwconsole r immediately after the fwconsole restart, the BLFs start working again.

You might suggest, “Don’t do an ‘fwconsole restart’”. I can avoid that, but, when I reboot the machine, I am in the same borked up BLF situation and have to run an fwconsole r to restore proper operation. Again, not a big deal if I’m around, but, if we have a power failure and I’m not around, BLFs will remained broken.

Steps to reproduce:
fwconsole restart
asterisk -rx ‘core show hints’ | grep ext-local | wc -l
That produces a count of “4”.

Resolution steps
fwconsole r
asterisk -rx ‘core show hints’ | grep ext-local | wc -l
That now produces the expected count of 133.

Any suggestions?

What does the Asterisk log show?

I’m not sure what to look for nor in which logfile to check.

Can you provide suggestions?

/var/log/asterisk/full

There will be a large chunk of messages at the time of the restart. Near the end of that, you may find some clues about your BLF situation.

That helps. But, I end up with 18,882 lines of info in full regarding a restart. So, I’m not sure what to look for therein.

This is fairly normal. Asterisk does not keep track of subscriptions when it’s shutdown. It waits for phones to “reconnect” with it and “ask [subscribe] to the hints again”. When you reload several things can happen, but this can also come down to timing.

Ahhh, ok. So, after a time, they should start working again all on their own?

Depends on the phone. What are yours?

What type of phones are you using? Yes the phone has to resubsribe it hints. When asterisk restarts they are all lost.

Grandstream GXV3240s

OK well its up to your device to resubsribe it hints. For example Sangoma and Digium phones do this whenever they do a re-register which by default is every 60 seconds so they are always keeping the PBX updated with their current hints. Other phones do it their own way. For example Aastra use to only on boot and recently I am told they added a BLF Resubsribe interval you can set.

fwconsole restart followed by phone reboots of the monitoring and monitored extensions did not restore BLF functionality.

I know that the GXV3240s resubscribe during a reboot, so, the BLFs should start working after the phone reboots.

So, I think there is something else afoot.

I have dumped the output of core show hints and sip show subscriptions both before and after the reload. Would that be heplful to post? (And is there any security risk?)

You would need to get a PCAP from the PBX to see if the phone it hitting it and requesting the BLF Subsriptions or enable SIP Debug on the IP address in Asterisk.

Phone rebooted at 15:59 or so.

tshark capture thusly:
tshark -i eth0 -t a -R 'sip.Request-Line contains "REGISTER" or sip.Request-Line contains "SUBSCRIBE"'

Still no BLFs.

Output of tshark:

* 16:00:03.138496 192.168.2.103 -> 192.168.2.44  SIP 507 Request: REGISTER sip:192.168.2.44    (remove all bindings) | 
* 16:00:03.145762 192.168.2.103 -> 192.168.2.44  SIP 665 Request: REGISTER sip:192.168.2.44    (remove all bindings) | 
* 16:00:04.154226 192.168.2.103 -> 192.168.2.44  SIP 786 Request: REGISTER sip:192.168.2.44 | 
* 16:00:04.157240 192.168.2.103 -> 192.168.2.44  SIP 786 Request: REGISTER sip:192.168.2.44 | 
* 16:00:04.166697 192.168.2.103 -> 192.168.2.44  SIP 656 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.169835 192.168.2.103 -> 192.168.2.44  SIP 820 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.177066 192.168.2.103 -> 192.168.2.44  SIP 683 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.180082 192.168.2.103 -> 192.168.2.44  SIP 846 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.190609 192.168.2.103 -> 192.168.2.44  SIP 685 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.193580 192.168.2.103 -> 192.168.2.44  SIP 848 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.203989 192.168.2.103 -> 192.168.2.44  SIP 684 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.207044 192.168.2.103 -> 192.168.2.44  SIP 847 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.217367 192.168.2.103 -> 192.168.2.44  SIP 684 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.220465 192.168.2.103 -> 192.168.2.44  SIP 847 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.230871 192.168.2.103 -> 192.168.2.44  SIP 684 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.234089 192.168.2.103 -> 192.168.2.44  SIP 847 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.245032 192.168.2.103 -> 192.168.2.44  SIP 685 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.248105 192.168.2.103 -> 192.168.2.44  SIP 845 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.258701 192.168.2.103 -> 192.168.2.44  SIP 683 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.261920 192.168.2.103 -> 192.168.2.44  SIP 847 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.272572 192.168.2.103 -> 192.168.2.44  SIP 685 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.275500 192.168.2.103 -> 192.168.2.44  SIP 848 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.286695 192.168.2.103 -> 192.168.2.44  SIP 686 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.290119 192.168.2.103 -> 192.168.2.44  SIP 848 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.300948 192.168.2.103 -> 192.168.2.44  SIP 685 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.304162 192.168.2.103 -> 192.168.2.44  SIP 849 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.314982 192.168.2.103 -> 192.168.2.44  SIP 685 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.318160 192.168.2.103 -> 192.168.2.44  SIP 848 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.329845 192.168.2.103 -> 192.168.2.44  SIP 685 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.333026 192.168.2.103 -> 192.168.2.44  SIP 846 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.344010 192.168.2.103 -> 192.168.2.44  SIP 685 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.347271 192.168.2.103 -> 192.168.2.44  SIP 847 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.357388 192.168.2.103 -> 192.168.2.44  SIP 683 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.360898 192.168.2.103 -> 192.168.2.44  SIP 845 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.370952 192.168.2.103 -> 192.168.2.44  SIP 686 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.374153 192.168.2.103 -> 192.168.2.44  SIP 849 Request: SUBSCRIBE sip:[email protected] | 
* 16:00:04.392117 192.168.2.103 -> 192.168.2.44  SIP 690 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.395832 192.168.2.103 -> 192.168.2.44  SIP 856 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.406321 192.168.2.103 -> 192.168.2.44  SIP 692 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.409747 192.168.2.103 -> 192.168.2.44  SIP 856 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.420444 192.168.2.103 -> 192.168.2.44  SIP 692 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.423788 192.168.2.103 -> 192.168.2.44  SIP 857 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.435288 192.168.2.103 -> 192.168.2.44  SIP 691 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.438742 192.168.2.103 -> 192.168.2.44  SIP 857 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.449722 192.168.2.103 -> 192.168.2.44  SIP 692 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.453275 192.168.2.103 -> 192.168.2.44  SIP 857 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.465540 192.168.2.103 -> 192.168.2.44  SIP 690 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.469338 192.168.2.103 -> 192.168.2.44  SIP 856 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.476321 192.168.2.103 -> 192.168.2.44  SIP 691 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.480201 192.168.2.103 -> 192.168.2.44  SIP 857 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.487427 192.168.2.103 -> 192.168.2.44  SIP 691 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.491434 192.168.2.103 -> 192.168.2.44  SIP 857 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.498579 192.168.2.103 -> 192.168.2.44  SIP 691 Request: SUBSCRIBE sip:*[email protected] | 
* 16:00:04.502749 192.168.2.103 -> 192.168.2.44  SIP 857 Request: SUBSCRIBE sip:*[email protected] |

What version of Asterisk is this? In the lab I’m not able to reproduce. Furthermore the phone would in no way ever know a reload happened.

Also when the subscribe is “heard” from Asterisk it’ll be on the CLI of Asterisk.

Asterisk 13.13.1

And, FYI, I did not see the SUBSCRIBEs on the CLI during the reboot:

  • [[email protected] tmp]# asterisk -vvvr
  • Asterisk 13.13.1, Copyright © 1999 - 2014, Digium, Inc. and others.
  • Created by Mark Spencer [email protected]
  • Asterisk comes with ABSOLUTELY NO WARRANTY; type ‘core show warranty’ for details.
  • This is free software, with components licensed under the GNU General Public
  • License version 2 and other licenses; you are welcome to redistribute it under
  • certain conditions. Type ‘core show license’ for details.
  • =========================================================================
  • Connected to Asterisk 13.13.1 currently running on pbx (pid = 11412)
  • [2016-12-27 16:13:08] NOTICE[11493]: chan_sip.c:29962 sip_poke_noanswer: Peer ‘5501’ is now UNREACHABLE! Last qualify: 2
  • [2016-12-27 16:13:32] NOTICE[11493]: chan_sip.c:24443 handle_response_peerpoke: Peer ‘5501’ is now Reachable. (8ms / 2000ms)
  • -- Unregistered SIP '5501'
    
  • -- Registered SIP '5501' at 192.168.2.103:5060

I should have clarified that you need to turn on the proper level of verbosity and debugging to see these messages.

But your wireshark also clearly shows no request is coming on reboot so that should be enough for you to get with GS on.

Tony,

I’m not sure what you mean.

The tshark output shows both an SIP REGISTER and an SIP SUBSCRIBE message from the phone (192.168.2.103) to the PBX (192.168.2.44) on phone reboot.