[asterisk-bugs] [JIRA] (ASTERISK-29344) AMI Contact events getting dropped

Joshua C. Colp (JIRA) noreply at issues.asterisk.org
Fri Mar 12 13:25:15 CST 2021


    [ https://issues.asterisk.org/jira/browse/ASTERISK-29344?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=254150#comment-254150 ] 

Joshua C. Colp commented on ASTERISK-29344:
-------------------------------------------

I'd suggest attaching logs of non-working and working cases with complete debug level output including the AMI events instead of embedding the information as comments in here, it makes it hard to move around and see. The debug information also contains information about determining the status of things, including if they change or don't change.

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