Device hints & states after reloading config / restart not updated fully?

Current Asterisk Version: 11.23.0, FreePBX 13.0.167, FreePBX Distro 10.13.66-15, D&U mode; but I have been noticing this behavior earlier too; only could not figure out the pattern so far . But this time I think I noticed what’s changing, so here goes:

normally my Asterisk Info would show e.g. in queues:

200 has 0 calls (max unlimited) in 'ringall' strategy (3s holdtime, 91s talktime), W:0, C:7, A:1, SL:100.0% within 30s
      26 A (Local/26@from-queue/n from hint:26@ext-local) (ringinuse enabled) (Not in use) has taken 4 calls (last was 6406 secs ago)
      22 B (Local/22@from-queue/n from hint:22@ext-local) (ringinuse enabled) (Not in use) has taken 1 calls (last was 11291 secs ago)
      31 C (Local/31@from-queue/n from hint:31@ext-local) (ringinuse enabled) (Not in use) has taken 2 calls (last was 952 secs ago)
      21 D (Local/21@from-queue/n from hint:21@ext-local) (ringinuse enabled) (Not in use) has taken no calls yet
   No Callers

and in hints

-= Registered Asterisk Dial Plan Hints =-
           *46*1021*200@ext-queues          : qpause:200:Local/21@  State:Idle            Watchers  0
                  *8570@park-hints          : park:71@parkedcalls&  State:Idle            Watchers  0
           *46*1022*200@ext-queues          : qpause:200:Local/22@  State:Idle            Watchers  0
                _*46*X.@ext-queues          : ${DB(AMPUSER/${EXTEN  State:Unavailable     Watchers  0
                   *272@timeconditions-toggl: Custom:TC2            State:InUse           Watchers  1
                   *271@timeconditions-toggl: Custom:TC1            State:Idle            Watchers  1
                 _*98X.@app-dialvm          : MWI:${EXTEN:3}@${DB(  State:Unavailable     Watchers  0
                     72@park-hints          : park:72@parkedcalls   State:Unavailable     Watchers  3
                     73@park-hints          : park:73@parkedcalls   State:Unavailable     Watchers  3
                     71@park-hints          : park:71@parkedcalls   State:Unavailable     Watchers  3
                     76@park-hints          : park:76@parkedcalls   State:Unavailable     Watchers  3
                     77@park-hints          : park:77@parkedcalls   State:Idle            Watchers  1
                     74@park-hints          : park:74@parkedcalls   State:Unavailable     Watchers  3
                     75@park-hints          : park:75@parkedcalls   State:Unavailable     Watchers  3
                     78@park-hints          : park:78@parkedcalls   State:Idle            Watchers  1
                 _*21X.@ext-findmefollow    : Custom:FOLLOWME${EXT  State:Unavailable     Watchers  0
                 _*80X.@ext-local           : ${DB(AMPUSER/${EXTEN  State:Unavailable     Watchers  0
                     26@ext-local           : SIP/5026&SIP/26&Cust  State:Idle            Watchers  3
                     25@ext-local           : SIP/5025&SIP/1025&Cu  State:Unavailable     Watchers  1
                     24@ext-local           : SIP/1024&Custom:DND2  State:Idle            Watchers  0
                     22@ext-local           : SIP/1022&SIP/22&Cust  State:Idle            Watchers  2
                     21@ext-local           : SIP/5021&SIP/5022&SI  State:Idle            Watchers  3
               *45*1025@ext-queues          : Custom:QUEUE1025*200  State:Idle            Watchers  0
                 _*85X.@park-hints          : park:71@parkedcalls&  State:Idle            Watchers  0
                 *45*30@ext-queues          : Custom:QUEUE30*200    State:Idle            Watchers  0
                     37@ext-local           : SIP/5037&SIP/37&SIP/  State:Idle            Watchers  2
                     30@ext-local           : SIP/5030&SIP/5031&SI  State:Idle            Watchers  2
                     31@ext-local           : SIP/1031&SIP/31&Cust  State:Idle            Watchers  2
                 _*76X.@ext-dnd-hints       : Custom:DEVDND${EXTEN  State:Unavailable     Watchers  0
                 _*96X.@ext-cf-hints        : Custom:DEVCF${EXTEN:  State:Unavailable     Watchers  0
               *46*1022@ext-queues          : qpause:200:Local/22@  State:Idle            Watchers  0
               *46*1021@ext-queues          : qpause:200:Local/21@  State:Idle            Watchers  0
                  *8025@ext-local           : SIP/5025&SIP/1025&Cu  State:Unavailable     Watchers  0
                  *8024@ext-local           : SIP/1024&Custom:DND2  State:Idle            Watchers  0
             _*45XX*XXX@ext-queues          : Custom:QUEUE${EXTEN:  State:Unavailable     Watchers  0
                  *8026@ext-local           : SIP/5026&SIP/26&Cust  State:Idle            Watchers  0
                  *8021@ext-local           : SIP/5021&SIP/5022&SI  State:Idle            Watchers  0
           _*45XXXX*XXX@ext-queues          : Custom:QUEUE${EXTEN:  State:Unavailable     Watchers  0
                  *8022@ext-local           : SIP/1022&SIP/22&Cust  State:Idle            Watchers  0
                  *8037@ext-local           : SIP/5037&SIP/37&SIP/  State:Idle            Watchers  0
                  *8030@ext-local           : SIP/5030&SIP/5031&SI  State:Idle            Watchers  0
                  *8031@ext-local           : SIP/1031&SIP/31&Cust  State:Idle            Watchers  0
               *45*5031@ext-queues          : Custom:QUEUE5031*200  State:Idle            Watchers  0
               *45*5030@ext-queues          : Custom:QUEUE5030*200  State:Idle            Watchers  0
               *45*5025@ext-queues          : Custom:QUEUE5025*200  State:Idle            Watchers  0
                  *8421@ext-local           : ccss:SIP/5021&ccss:S  State:Unavailable     Watchers  0
                  *8422@ext-local           : ccss:SIP/1022&ccss:S  State:Unavailable     Watchers  0
                  *8425@ext-local           : ccss:SIP/5025&ccss:S  State:Unavailable     Watchers  0
                  *8424@ext-local           : ccss:SIP/1024         State:Unavailable     Watchers  0
                  *8426@ext-local           : ccss:SIP/5026&ccss:S  State:Unavailable     Watchers  0
                  *8430@ext-local           : ccss:SIP/5030&ccss:S  State:Unavailable     Watchers  0
                  *8431@ext-local           : ccss:SIP/1031&ccss:S  State:Unavailable     Watchers  0
                  *8437@ext-local           : ccss:SIP/5037&ccss:S  State:Unavailable     Watchers  0
                    *85@park-hints          : park:71@parkedcalls&  State:Idle            Watchers  0
- 54 hints registered

but sometimes, after restart or reload, the queue shows ‘Invalid’ in status field (here Not in use); and about half of the hints are missing (mostly those related to the presence/status/cw).

This causes one of my softphones to not show the appropriate blf status (somehow the hardphones -S500’s- do show BLF status right)

Not sure whether this is my box’s problem or the softphone, but when I tried changing transport protocol (udp to tcp and back again to udp - the device it registers as, has actually All - UDP Primary transport selected and NAT : No (no)); It then did register, and has subscribed to the presence hints, which have subsequently magically appeared in Asterisk Info (as pasted above).

Where should I look to get more info to present here? (anything specific to look for in the logs possibly ?)

After a restart you will end up losing your hint watchers because Asterisk does not remember that when it’s off. The phone will have to resubscribe to the hint. Also all hints in freepbx 13 are dynamic so they won’t show up until they are subscribed to.

Having looked into application logs (that also log the SIP dialog which is handy) right after start, this happens:

  • the application performs the REGISTER dialog which looks like is successful
  • then it sends SUBSCIRBE, only to receive UNAUTHORIZED to every request for a while (about 1.036 s)
  • then it sends SUBSCRIBEs again, receives OK for time call flow hints and for call park hints, but not to number hints
  • to subsequent SUBSCRIBE requests to the number hints it receives NOT FOUND

What’s puzzling, is that yesterday I managed to de-authorize and re-authorize and the hints have registered; presumably ‘raced’ something? or maybe the application does things too fast? - but can not replicate any more.

I have logs, I could share but they’re a tad large to anonymize all the cookies…