Hi,

recently i upgraded my setup from Asterisk 13.21 to 13.29 and noticed some strange behavior related to Asterisks internal states. I never had problems like this before (same problem occurs on 13.32);

First i added the new endpoint '7777':


2020-04-09T11:02:05.000586Z       124 Execute   REPLACE INTO ps_aors (
                id,
                max_contacts,
                remove_existing,
                qualify_frequency
            )
            VALUES ('7777', '1', 'yes', '60')


2020-04-09T11:02:05.001362Z       124 Execute   REPLACE INTO ps_auths
            (id, auth_type, md5_cred, password, realm, username)
            VALUES ('7777', 'userpass', NULL, 'a05RAGsBUbjL0fws', NULL, '7777')


2020-04-09T11:02:05.002705Z       124 Execute   REPLACE INTO ps_endpoints (
                id,
                allow,
                aors,
                auth,
                callerid,
                context,
                direct_media,
                disable_direct_media_on_nat,
                disallow,
                dtmf_mode,
                force_rport,
                from_domain,
                from_user,
                ice_support,
                language,
                mailboxes,
                media_encryption,
                media_encryption_optimistic,
                outbound_auth,
                rewrite_contact,
                rtp_symmetric,
                send_pai,
                send_rpid,
                set_var,
                transport,
                trust_id_inbound,
                trust_id_outbound
            )
            VALUES ('7777', 'alaw', '7777', '7777', NULL, 'from-internal-users', 'no', NULL, 'all', 'rfc4733', NULL, NULL, NULL, NULL, 'en', '7777@default', NULL, NULL, NULL, NULL, NULL, 'yes', 'no', NULL, 'udp', 'no', NULL)


After i used Registers to connect my newly added endpoint to the Asterisk the internal state got messed up;


Endpoint:  1337/1337 Unavailable   0 of inf
     InAuth:  1337/1337
        Aor:  1337                                               1
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  7777/7777 Not in use    0 of inf
     InAuth:  7777/7777
        Aor:  7777                                               1
      Contact:  7777/sip:7777@10.0.0.101:5060 3588554430 Avail         7.279
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  8888/8888 Unavailable   0 of inf
     InAuth:  8888/8888
        Aor:  8888                                               1
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  950001/950001 Unavailable   0 of inf
     InAuth:  950001/950001
        Aor:  950001                                             1
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  950002/950002 Unavailable   0 of inf
     InAuth:  950002/950002
        Aor:  950002                                             1
      Contact:  950002/sip:950002@10.0.0.102:5060 09a8bf6699 Avail         7.049
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  950003/950003 Unavailable   0 of inf
     InAuth:  950003/950003
        Aor:  950003                                             1
      Contact:  950003/sip:950003@10.0.0.100:5060 a8eec70ece Avail         8.207
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  950004/950004 Unavailable   0 of inf
     InAuth:  950004/950004
        Aor:  950004                                             1
      Contact:  950004/sip:950004@10.0.0.103:5060 47c21f1e25 Avail        12.306
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  999999 Unavailable   0 of inf
     InAuth:  999999/999999
        Aor:  999999                                             1
  Transport:  udp                       udp      0      0 0.0.0.0:5060


Every endpoint now has the state 'Unavailable' but the newly added Endpoint '7777'.
The Aors Contact information is still correct telling 'Avail'

All hints now look as follow;


1337@from-internal-u: PJSIP/1337            State:Unavailable Presence:not_set         Watchers  0 *8*00001@from-intern: PJSIP/999999          State:Unavailable Presence:not_set         Watchers  0 8888@from-internal-u: PJSIP/8888            State:Unavailable Presence:not_set         Watchers  0 7777@from-internal-u: PJSIP/7777            State:Idle Presence:not_set         Watchers  0 999999@from-internal: PJSIP/999999          State:Unavailable Presence:not_set         Watchers  0


When i now try to change states of my endpoints nothing changes at all. Even when two endpoints are in a working call the internal state still tells 'Unavailable'

After doing a 'reload res_pjsip.so' Asterisk works fine and the states are dynamic again;


Endpoint:  1337/1337 Unavailable   0 of inf
     InAuth:  1337/1337
        Aor:  1337                                               1
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  7777/7777 Not in use    0 of inf
     InAuth:  7777/7777
        Aor:  7777                                               1
      Contact:  7777/sip:7777@10.0.0.101:5060 3588554430 Avail         6.606
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  8888/8888 Unavailable   0 of inf
     InAuth:  8888/8888
        Aor:  8888                                               1
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  950001/950001 Unavailable   0 of inf
     InAuth:  950001/950001
        Aor:  950001                                             1
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  950002/950002 Not in use    0 of inf
     InAuth:  950002/950002
        Aor:  950002                                             1
      Contact:  950002/sip:950002@10.0.0.102:5060 09a8bf6699 Avail         7.464
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  950003/950003 Not in use    0 of inf
     InAuth:  950003/950003
        Aor:  950003                                             1
      Contact:  950003/sip:950003@10.0.0.100:5060 a8eec70ece Avail         7.548
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  950004/950004 Not in use    0 of inf
     InAuth:  950004/950004
        Aor:  950004                                             1
      Contact:  950004/sip:950004@10.0.0.103:5060 47c21f1e25 Avail         8.569
  Transport:  udp                       udp      0      0 0.0.0.0:5060

 Endpoint:  999999 Unavailable   0 of inf
     InAuth:  999999/999999
        Aor:  999999                                             1
  Transport:  udp                       udp      0      0 0.0.0.0:5060


I didn't need a reload when i was on Asterisk 13.21.

some interesting lines from debug log (full log attached):


[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Synchronizing endpoint '1337' with AORs '1337' [Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Filtered AOR '1337' on endpoint '1337' as we are looking for '7777' [Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Endpoint '1337' has no AORs feeding it, setting it to offline state as default [Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Synchronizing endpoint '7777' with AORs '7777' [Apr  9 11:04:00] DEBUG[7081] res_pjsip/pjsip_options.c: Adding endpoint compositor '7777' to AOR '7777' [Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Synchronizing endpoint '8888' with AORs '8888' [Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Filtered AOR '8888' on endpoint '8888' as we are looking for '7777' [Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Endpoint '8888' has no AORs feeding it, setting it to offline state as default [Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Synchronizing endpoint '950001' with AORs '950001' [Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Filtered AOR '950001' on endpoint '950001' as we are looking for '7777' [Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Endpoint '950001' has no AORs feeding it, setting it to offline state as default [Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Synchronizing endpoint '950002' with AORs '950002' [Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Filtered AOR '950002' on endpoint '950002' as we are looking for '7777' [Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Endpoint '950002' has no AORs feeding it, setting it to offline state as default


Did something change after Asterisk 13.21 how endpoints should be added/handled or am i missing some new feature like 'syncing local endpoint state to database'?


Best Regards,

Silvan

Event: SuccessfulAuth
Privilege: security,all
EventTV: 2020-04-09T11:04:00.643+0000
Severity: Informational
Service: PJSIP
EventVersion: 1
AccountID: 7777
SessionID: 0_3917826643@10.0.0.101
LocalAddress: IPV4/UDP/192.168.122.38/5060
RemoteAddress: IPV4/UDP/10.0.0.101/5060
UsingPassword: 1


[Apr  9 11:04:00] DEBUG[7081] res_config_mysql.c: MySQL RealTime: Connection 
okay.
[Apr  9 11:04:00] DEBUG[7081] res_config_mysql.c: MySQL RealTime: Retrieve SQL: 
SELECT * FROM ps_domain_aliases WHERE id = '10.0.0.1'
[Apr  9 11:04:00] DEBUG[7081] res_pjsip_registrar.c: Matched id '7777' to aor 
'7777'
[Apr  9 11:04:00] DEBUG[7081] res_pjsip_registrar.c: Matched aor '7777' by To 
username
[Apr  9 11:04:00] DEBUG[7081] res_config_mysql.c: MySQL RealTime: Connection 
okay.
[Apr  9 11:04:00] DEBUG[7081] res_config_mysql.c: MySQL RealTime: Retrieve SQL: 
SELECT * FROM ps_aors_view WHERE id = '7777'
[Apr  9 11:04:00] DEBUG[7081] config.c: extract double from [3.0] in [-inf, 
inf] gives [3.000000](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [7200] in [0, 
4294967295] gives [7200](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [3600] in [0, 
4294967295] gives [3600](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [60] in [0, 
4294967295] gives [60](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [1] in [0, 
4294967295] gives [1](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [60] in [0, 86400] 
gives [60](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract double from [3.0] in [-inf, 
inf] gives [3.000000](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] res_config_mysql.c: MySQL RealTime: Connection 
okay.
[Apr  9 11:04:00] DEBUG[7081] res_config_mysql.c: MySQL RealTime: Retrieve SQL: 
SELECT * FROM ps_aors_view WHERE id = '7777'
[Apr  9 11:04:00] DEBUG[7081] config.c: extract double from [3.0] in [-inf, 
inf] gives [3.000000](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [7200] in [0, 
4294967295] gives [7200](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [3600] in [0, 
4294967295] gives [3600](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [60] in [0, 
4294967295] gives [60](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [1] in [0, 
4294967295] gives [1](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [60] in [0, 86400] 
gives [60](0)
[Apr  9 11:04:00] DEBUG[7082] res_config_mysql.c: MySQL RealTime: Connection 
okay.
[Apr  9 11:04:00] DEBUG[7082] res_config_mysql.c: MySQL RealTime: Retrieve SQL: 
SELECT * FROM ps_aors_view WHERE id = '7777'
[Apr  9 11:04:00] DEBUG[7082] config.c: extract double from [3.0] in [-inf, 
inf] gives [3.000000](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [7200] in [0, 
4294967295] gives [7200](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [3600] in [0, 
4294967295] gives [3600](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [60] in [0, 
4294967295] gives [60](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [1] in [0, 
4294967295] gives [1](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [60] in [0, 86400] 
gives [60](0)
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: AOR '7777' qualify 
options have been modified. Synchronize an AOR local state
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Configuring AOR '7777' 
with current state of configuration and world
[Apr  9 11:04:00] DEBUG[7082] config.c: extract double from [3.0] in [-inf, 
inf] gives [3.000000](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract double from [3.000000] in 
[-inf, inf] gives [3.000000](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [5060] in [0, 
4294967295] gives [5060](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [60] in [0, 86400] 
gives [60](0)
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: AOR '7777' has 
transitioned from unqualified to qualified, reset available contacts to 0
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: AOR '7777' now has 0 
available contacts
[Apr  9 11:04:00] DEBUG[7081] res_config_mysql.c: MySQL RealTime: Connection 
okay.
[Apr  9 11:04:00] DEBUG[7081] res_config_mysql.c: MySQL RealTime: Retrieve SQL: 
SELECT * FROM ps_transports WHERE id = 'udp'
[Apr  9 11:04:00] DEBUG[7081] res_sorcery_realtime.c: Filtering out realtime 
field 'scheme' from retrieval
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [1] in [0, 
4294967295] gives [1](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 65535] 
gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract int from [100] in [1, 
2147483647] gives [100](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [1] in [0, 
4294967295] gives [1](0)
[Apr  9 11:04:00] DEBUG[7081] netsock2.c: Splitting '10.0.0.0' into...
[Apr  9 11:04:00] DEBUG[7081] netsock2.c: ...host '10.0.0.0' and port ''.
[Apr  9 11:04:00] DEBUG[7081] acl.c: 10.0.0.0:0/255.0.0.0:0 sense 0 appended to 
ACL
[Apr  9 11:04:00] DEBUG[7081] netsock2.c: Splitting '192.168.0.0' into...
[Apr  9 11:04:00] DEBUG[7081] netsock2.c: ...host '192.168.0.0' and port ''.
[Apr  9 11:04:00] DEBUG[7081] acl.c: 192.168.0.0:0/255.255.0.0:0 sense 0 
appended to ACL
[Apr  9 11:04:00] DEBUG[7081] netsock2.c: Splitting '172.16.0.0' into...
[Apr  9 11:04:00] DEBUG[7081] netsock2.c: ...host '172.16.0.0' and port ''.
[Apr  9 11:04:00] DEBUG[7081] acl.c: 172.16.0.0:0/255.240.0.0:0 sense 0 
appended to ACL
[Apr  9 11:04:00] DEBUG[7081] netsock2.c: Splitting '10.0.0.101' into...
[Apr  9 11:04:00] DEBUG[7081] netsock2.c: ...host '10.0.0.101' and port ''.
[Apr  9 11:04:00] DEBUG[7081] res_pjsip_nat.c: Request is being sent to local 
address, skipping NAT manipulation
[Apr  9 11:04:00] DEBUG[7082] res_config_mysql.c: MySQL RealTime: Connection 
okay.
[Apr  9 11:04:00] DEBUG[7082] res_config_mysql.c: MySQL RealTime: Retrieve SQL: 
SELECT * FROM ps_endpoints_view WHERE id LIKE '%' ESCAPE '\\' ORDER BY id
[Apr  9 11:04:00] DEBUG[7082] res_sorcery_realtime.c: Filtering out realtime 
field 'disallow' from retrieval
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [1800] in [0, 
4294967295] gives [1800](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [90] in [0, 
4294967295] gives [90](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] res_sorcery_realtime.c: Filtering out realtime 
field 'disallow' from retrieval
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [1800] in [0, 
4294967295] gives [1800](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [90] in [0, 
4294967295] gives [90](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] res_sorcery_realtime.c: Filtering out realtime 
field 'disallow' from retrieval
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [1800] in [0, 
4294967295] gives [1800](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [90] in [0, 
4294967295] gives [90](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] res_sorcery_realtime.c: Filtering out realtime 
field 'disallow' from retrieval
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [1800] in [0, 
4294967295] gives [1800](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [90] in [0, 
4294967295] gives [90](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] res_sorcery_realtime.c: Filtering out realtime 
field 'disallow' from retrieval
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [1800] in [0, 
4294967295] gives [1800](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [90] in [0, 
4294967295] gives [90](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] res_sorcery_realtime.c: Filtering out realtime 
field 'disallow' from retrieval
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [1800] in [0, 
4294967295] gives [1800](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [90] in [0, 
4294967295] gives [90](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] res_sorcery_realtime.c: Filtering out realtime 
field 'disallow' from retrieval
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [1800] in [0, 
4294967295] gives [1800](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [90] in [0, 
4294967295] gives [90](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] res_sorcery_realtime.c: Filtering out realtime 
field 'disallow' from retrieval
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [1800] in [0, 
4294967295] gives [1800](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [90] in [0, 
4294967295] gives [90](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Synchronizing endpoint 
'1337' with AORs '1337'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Filtered AOR '1337' on 
endpoint '1337' as we are looking for '7777'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Endpoint '1337' has no 
AORs feeding it, setting it to offline state as default
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Synchronizing endpoint 
'7777' with AORs '7777'
[Apr  9 11:04:00] DEBUG[7081] res_pjsip/pjsip_options.c: Adding endpoint 
compositor '7777' to AOR '7777'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Synchronizing endpoint 
'8888' with AORs '8888'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Filtered AOR '8888' on 
endpoint '8888' as we are looking for '7777'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Endpoint '8888' has no 
AORs feeding it, setting it to offline state as default
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Synchronizing endpoint 
'950001' with AORs '950001'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Filtered AOR '950001' 
on endpoint '950001' as we are looking for '7777'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Endpoint '950001' has 
no AORs feeding it, setting it to offline state as default
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Synchronizing endpoint 
'950002' with AORs '950002'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Filtered AOR '950002' 
on endpoint '950002' as we are looking for '7777'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Endpoint '950002' has 
no AORs feeding it, setting it to offline state as default
[Apr  9 11:04:00] DEBUG[7158] manager.c: Examining AMI event:
Event: PeerStatus
Privilege: system,all
ChannelType: PJSIP
Peer: PJSIP/950002
PeerStatus: Unreachable


[Apr  9 11:04:00] DEBUG[7053] devicestate.c: No provider found, checking 
channel drivers for PJSIP - 950002
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Synchronizing endpoint 
'950003' with AORs '950003'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Filtered AOR '950003' 
on endpoint '950003' as we are looking for '7777'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Endpoint '950003' has 
no AORs feeding it, setting it to offline state as default
[Apr  9 11:04:00] DEBUG[7158] manager.c: Examining AMI event:
Event: PeerStatus
Privilege: system,all
ChannelType: PJSIP
Peer: PJSIP/950003
PeerStatus: Unreachable


[Apr  9 11:04:00] DEBUG[7053] res_config_mysql.c: MySQL RealTime: Connection 
okay.
[Apr  9 11:04:00] DEBUG[7053] res_config_mysql.c: MySQL RealTime: Retrieve SQL: 
SELECT * FROM ps_endpoints_view WHERE id = '950002'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Synchronizing endpoint 
'950004' with AORs '950004'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Filtered AOR '950004' 
on endpoint '950004' as we are looking for '7777'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Endpoint '950004' has 
no AORs feeding it, setting it to offline state as default
[Apr  9 11:04:00] DEBUG[7158] manager.c: Examining AMI event:
Event: PeerStatus
Privilege: system,all
ChannelType: PJSIP
Peer: PJSIP/950004
PeerStatus: Unreachable


[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Synchronizing endpoint 
'999999' with AORs '999999'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Filtered AOR '999999' 
on endpoint '999999' as we are looking for '7777'
[Apr  9 11:04:00] DEBUG[7082] res_pjsip/pjsip_options.c: Endpoint '999999' has 
no AORs feeding it, setting it to offline state as default
[Apr  9 11:04:00] DEBUG[7088] res_pjsip_mwi.c: Created unsolicited MWI 
subscription for endpoint 7777
[Apr  9 11:04:00] DEBUG[7088] stasis.c: Topic 'mwi:all/7777@default': 
0x7f3c2c00d398 created
[Apr  9 11:04:00] DEBUG[7088] res_pjsip_mwi.c: Creating stasis MWI subscription 
to mailbox 7777@default for endpoint 7777.  Topic: 
'mwi:all/7777@default':0x7f3c2c00d398 2
[Apr  9 11:04:00] DEBUG[7158] manager.c: Examining AMI event:
Event: ContactStatus
Privilege: system,all
URI: sip:7777@10.0.0.101:5060
ContactStatus: Created
AOR: 7777
EndpointName: 7777
RoundtripUsec: 0


[Apr  9 11:04:00] DEBUG[7053] res_sorcery_realtime.c: Filtering out realtime 
field 'disallow' from retrieval
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [1800] in [0, 
4294967295] gives [1800](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [90] in [0, 
4294967295] gives [90](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] devicestate.c: Changing state for PJSIP/950002 - 
state 5 (Unavailable)
[Apr  9 11:04:00] DEBUG[7053] devicestate.c: No provider found, checking 
channel drivers for PJSIP - 950003
[Apr  9 11:04:00] DEBUG[7119] app_queue.c: Device 'PJSIP/950002' changed to 
state '5' (Unavailable) but we don't care because they're not a member of any 
queue.
[Apr  9 11:04:00] DEBUG[7158] manager.c: Examining AMI event:
Event: DeviceStateChange
Privilege: call,all
Device: PJSIP/950002
State: UNAVAILABLE


[Apr  9 11:04:00] DEBUG[7081] res_config_mysql.c: MySQL RealTime: Connection 
okay.
[Apr  9 11:04:00] DEBUG[7081] res_config_mysql.c: MySQL RealTime: Retrieve SQL: 
SELECT * FROM ps_endpoints_view WHERE id = '7777'
[Apr  9 11:04:00] DEBUG[7081] res_sorcery_realtime.c: Filtering out realtime 
field 'disallow' from retrieval
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [1800] in [0, 
4294967295] gives [1800](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [90] in [0, 
4294967295] gives [90](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] res_pjsip_mwi.c: Sending unsolicited MWI NOTIFY 
to endpoint 7777, new messages: 0, old messages: 0
[Apr  9 11:04:00] DEBUG[7053] res_config_mysql.c: MySQL RealTime: Connection 
okay.
[Apr  9 11:04:00] DEBUG[7053] res_config_mysql.c: MySQL RealTime: Retrieve SQL: 
SELECT * FROM ps_endpoints_view WHERE id = '950003'
[Apr  9 11:04:00] DEBUG[7053] res_sorcery_realtime.c: Filtering out realtime 
field 'disallow' from retrieval
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [1800] in [0, 
4294967295] gives [1800](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [90] in [0, 
4294967295] gives [90](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] devicestate.c: Changing state for PJSIP/950003 - 
state 5 (Unavailable)
[Apr  9 11:04:00] DEBUG[7053] devicestate.c: No provider found, checking 
channel drivers for PJSIP - 950004
[Apr  9 11:04:00] DEBUG[7119] app_queue.c: Device 'PJSIP/950003' changed to 
state '5' (Unavailable) but we don't care because they're not a member of any 
queue.
[Apr  9 11:04:00] DEBUG[7081] res_config_mysql.c: MySQL RealTime: Connection 
okay.
[Apr  9 11:04:00] DEBUG[7081] res_config_mysql.c: MySQL RealTime: Retrieve SQL: 
SELECT * FROM ps_aors_view WHERE id = '7777'
[Apr  9 11:04:00] DEBUG[7158] manager.c: Examining AMI event:
Event: DeviceStateChange
Privilege: call,all
Device: PJSIP/950003
State: UNAVAILABLE


[Apr  9 11:04:00] DEBUG[7081] config.c: extract double from [3.0] in [-inf, 
inf] gives [3.000000](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [7200] in [0, 
4294967295] gives [7200](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [3600] in [0, 
4294967295] gives [3600](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [60] in [0, 
4294967295] gives [60](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [1] in [0, 
4294967295] gives [1](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [60] in [0, 86400] 
gives [60](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract double from [3.0] in [-inf, 
inf] gives [3.000000](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract double from [3.000000] in 
[-inf, inf] gives [3.000000](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [5060] in [0, 
4294967295] gives [5060](0)
[Apr  9 11:04:00] DEBUG[7081] config.c: extract uint from [60] in [0, 86400] 
gives [60](0)
[Apr  9 11:04:00] DEBUG[7053] res_config_mysql.c: MySQL RealTime: Connection 
okay.
[Apr  9 11:04:00] DEBUG[7053] res_config_mysql.c: MySQL RealTime: Retrieve SQL: 
SELECT * FROM ps_endpoints_view WHERE id = '950004'
[Apr  9 11:04:00] DEBUG[7053] res_sorcery_realtime.c: Filtering out realtime 
field 'disallow' from retrieval
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [1800] in [0, 
4294967295] gives [1800](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [90] in [0, 
4294967295] gives [90](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] config.c: extract uint from [0] in [0, 
4294967295] gives [0](0)
[Apr  9 11:04:00] DEBUG[7053] devicestate.c: Changing state for PJSIP/950004 - 
state 5 (Unavailable)
[Apr  9 11:04:00] DEBUG[7119] app_queue.c: Device 'PJSIP/950004' changed to 
state '5' (Unavailable) but we don't care because they're not a member of any 
queue.
[Apr  9 11:04:00] DEBUG[7158] manager.c: Examining AMI event:
Event: DeviceStateChange
Privilege: call,all
Device: PJSIP/950004
State: UNAVAILABLE

-- 
_____________________________________________________________________
-- Bandwidth and Colocation Provided by http://www.api-digital.com --

asterisk-dev mailing list
To UNSUBSCRIBE or update options visit:
   http://lists.digium.com/mailman/listinfo/asterisk-dev

Reply via email to