[asterisk-bugs] [JIRA] (ASTERISK-29344) AMI Contact events getting dropped
Brian J. Murrell (JIRA)
noreply at issues.asterisk.org
Fri Mar 12 13:17:15 CST 2021
[ https://issues.asterisk.org/jira/browse/ASTERISK-29344?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=254149#comment-254149 ]
Brian J. Murrell commented on ASTERISK-29344:
---------------------------------------------
The endpoint status update in the successful case looks like:
{noformat}
[Mar 11 19:15:01] VERBOSE[30959] asterisk.c: Remote UNIX connection
[Mar 11 19:15:01] VERBOSE[1029] asterisk.c: Remote UNIX connection disconnected
[Mar 11 19:15:01] VERBOSE[1034] manager.c: Manager 'myasterisk' logged on from 127.0.0.1
[Mar 11 19:15:06] VERBOSE[960] res_pjsip_registrar.c: Added contact 'sip:example_ep at 10.75.22.32:50806;transport=tcp;pn-type=firebase;app-id=[redacted];pn-tok=[redacted];pn-timeout=0;pn-silent=1' to AOR 'example_ep' with expiration of 31536000 seconds
[Mar 11 19:15:06] VERBOSE[960] res_pjsip_registrar.c: Removed contact 'sip:example_ep at 10.75.22.32:50788;transport=tcp;pn-type=firebase;app-id=[redacted];pn-tok=[redacted];pn-timeout=0;pn-silent=1' from AOR 'example_ep' due to remove existing
[Mar 11 19:15:06] VERBOSE[961] res_pjsip/pjsip_options.c: Contact example_ep/sip:example_ep at 10.75.22.32:50788;transport=tcp;pn-type=firebase;app-id=[redacted];pn-tok=[redacted];pn-timeout=0;pn-silent=1 has been deleted
[Mar 11 19:15:06] VERBOSE[1034] manager.c: Manager 'myasterisk' logged off from 127.0.0.1
{noformat}
Are you saying the difference is the:
{noformat}
[Mar 11 19:15:06] VERBOSE[961] res_pjsip/pjsip_options.c: Contact example_ep/sip:example_ep at 10.75.22.32:50788;transport=tcp;pn-type=firebase;app-id=[redacted];pn-tok=[redacted];pn-timeout=0;pn-silent=1 has been deleted
{noformat}
If so, I'm not sure I understand the difference in those two cases. They are both cases of a contact that registers at some point for a very long time, and then comes back an re-registers. So why is one treated differently than the other?
> AMI Contact events getting dropped
> ----------------------------------
>
> Key: ASTERISK-29344
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-29344
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: General
> Affects Versions: 18.2.2
> Reporter: Brian J. Murrell
> Assignee: Brian J. Murrell
>
> I am experiencing what seems to be dropped AMI events, in particular when and endpoint registers. This doesn't happen all of the time, maybe about 10-20% of the time.
> Take for example this series of AMI events:
> {noformat}
> Thu Mar 11 19:15:06 EST 2021: Event: ChallengeSent
> Thu Mar 11 19:15:06 EST 2021: Privilege: security,all
> Thu Mar 11 19:15:06 EST 2021: Timestamp: 1615508106.775538
> Thu Mar 11 19:15:06 EST 2021: SystemName: pbx.example.com
> Thu Mar 11 19:15:06 EST 2021: EventTV: 2021-03-11T19:15:06.775-0500
> Thu Mar 11 19:15:06 EST 2021: Severity: Informational
> Thu Mar 11 19:15:06 EST 2021: Service: PJSIP
> Thu Mar 11 19:15:06 EST 2021: EventVersion: 1
> Thu Mar 11 19:15:06 EST 2021: AccountID: example_ep
> Thu Mar 11 19:15:06 EST 2021: SessionID: hIZfJDMpqE
> Thu Mar 11 19:15:06 EST 2021: LocalAddress: IPV4/TCP/10.75.22.8/5060
> Thu Mar 11 19:15:06 EST 2021: RemoteAddress: IPV4/TCP/10.75.22.32/50806
> Thu Mar 11 19:15:06 EST 2021: Challenge:
> Thu Mar 11 19:15:06 EST 2021:
> Thu Mar 11 19:15:06 EST 2021: Event: SuccessfulAuth
> Thu Mar 11 19:15:06 EST 2021: Privilege: security,all
> Thu Mar 11 19:15:06 EST 2021: Timestamp: 1615508106.857175
> Thu Mar 11 19:15:06 EST 2021: SystemName: pbx.example.com
> Thu Mar 11 19:15:06 EST 2021: EventTV: 2021-03-11T19:15:06.857-0500
> Thu Mar 11 19:15:06 EST 2021: Severity: Informational
> Thu Mar 11 19:15:06 EST 2021: Service: PJSIP
> Thu Mar 11 19:15:06 EST 2021: EventVersion: 1
> Thu Mar 11 19:15:06 EST 2021: AccountID: example_ep
> Thu Mar 11 19:15:06 EST 2021: SessionID: hIZfJDMpqE
> Thu Mar 11 19:15:06 EST 2021: LocalAddress: IPV4/TCP/10.75.22.8/5060
> Thu Mar 11 19:15:06 EST 2021: RemoteAddress: IPV4/TCP/10.75.22.32/50806
> Thu Mar 11 19:15:06 EST 2021: UsingPassword: 1
> Thu Mar 11 19:15:06 EST 2021:
> Thu Mar 11 19:15:06 EST 2021: Event: ContactStatus
> Thu Mar 11 19:15:06 EST 2021: Privilege: system,all
> Thu Mar 11 19:15:06 EST 2021: Timestamp: 1615508106.858452
> Thu Mar 11 19:15:06 EST 2021: SystemName: pbx.example.com
> Thu Mar 11 19:15:06 EST 2021: URI: sip:example_ep at 10.75.22.32:50806;transport=tcp;pn-type=firebase;app-id=[redacted];pn-tok=[redacted];pn-timeout=0;pn-silent=1
> Thu Mar 11 19:15:06 EST 2021: ContactStatus: NonQualified
> Thu Mar 11 19:15:06 EST 2021: AOR: example_ep
> Thu Mar 11 19:15:06 EST 2021: EndpointName: example_ep
> {noformat}
> We can see the endpoint being challenged and successfully authenticating followed by a ContactStatus event for the registration.
> Yet in this example:
> {noformat}
> Thu Mar 11 14:15:06 EST 2021: Event: ChallengeSent
> Thu Mar 11 14:15:06 EST 2021: Privilege: security,all
> Thu Mar 11 14:15:06 EST 2021: Timestamp: 1615490106.969337
> Thu Mar 11 14:15:06 EST 2021: SystemName: pbx.example.com
> Thu Mar 11 14:15:06 EST 2021: EventTV: 2021-03-11T14:15:06.969-0500
> Thu Mar 11 14:15:06 EST 2021: Severity: Informational
> Thu Mar 11 14:15:06 EST 2021: Service: PJSIP
> Thu Mar 11 14:15:06 EST 2021: EventVersion: 1
> Thu Mar 11 14:15:06 EST 2021: AccountID: example_ep
> Thu Mar 11 14:15:06 EST 2021: SessionID: hIZfJDMpqE
> Thu Mar 11 14:15:06 EST 2021: LocalAddress: IPV4/TCP/10.75.22.8/5060
> Thu Mar 11 14:15:06 EST 2021: RemoteAddress: IPV4/TCP/10.75.22.32/50328
> Thu Mar 11 14:15:06 EST 2021: Challenge:
> Thu Mar 11 14:15:06 EST 2021:
> Thu Mar 11 14:15:07 EST 2021: Event: SuccessfulAuth
> Thu Mar 11 14:15:07 EST 2021: Privilege: security,all
> Thu Mar 11 14:15:07 EST 2021: Timestamp: 1615490107.013907
> Thu Mar 11 14:15:07 EST 2021: SystemName: pbx.example.com
> Thu Mar 11 14:15:07 EST 2021: EventTV: 2021-03-11T14:15:07.013-0500
> Thu Mar 11 14:15:07 EST 2021: Severity: Informational
> Thu Mar 11 14:15:07 EST 2021: Service: PJSIP
> Thu Mar 11 14:15:07 EST 2021: EventVersion: 1
> Thu Mar 11 14:15:07 EST 2021: AccountID: example_ep
> Thu Mar 11 14:15:07 EST 2021: SessionID: hIZfJDMpqE
> Thu Mar 11 14:15:07 EST 2021: LocalAddress: IPV4/TCP/10.75.22.8/5060
> Thu Mar 11 14:15:07 EST 2021: RemoteAddress: IPV4/TCP/10.75.22.32/50328
> Thu Mar 11 14:15:07 EST 2021: UsingPassword: 1
> {noformat}
> There is the challenge and authentication events but no ContactStatus event. The endpoint definitely did register as can be seen in the console:
> {noformat}
> [Mar 11 14:15:02] VERBOSE[15685] asterisk.c: Remote UNIX connection
> [Mar 11 14:15:02] VERBOSE[494] asterisk.c: Remote UNIX connection disconnected
> [Mar 11 14:15:02] VERBOSE[498] manager.c: Manager 'myasterisk' logged on from 127.0.0.1
> [Mar 11 14:15:07] VERBOSE[538] res_pjsip_registrar.c: Added contact 'sip:example_ep at 10.75.22.32:50328;transport=tcp;pn-type=firebase;app-id=[redacted];pn-tok=[redacted];pn-timeout=0;pn-silent=1' to AOR 'example_ep' with expiration of 31536000 seconds
> [Mar 11 14:15:07] VERBOSE[538] res_pjsip_registrar.c: Removed contact 'sip:example_ep at 10.75.22.32:50252;transport=tcp;pn-type=firebase;app-id=[redacted];pn-tok=[redacted];pn-timeout=0;pn-silent=1' from AOR 'example_ep' due to remove existing
> [Mar 11 14:16:02] VERBOSE[498] manager.c: Manager 'myasterisk' logged off from 127.0.0.1
> {noformat}
> Which you can see happened within the connection to the manager.
--
This message was sent by Atlassian JIRA
(v6.2#6252)
More information about the asterisk-bugs
mailing list