[asterisk-bugs] [JIRA] (ASTERISK-27258) PJSIP issues and possible memory leaks????
Leon Zetekoff (JIRA)
noreply at issues.asterisk.org
Fri Sep 15 09:23:09 CDT 2017
[ https://issues.asterisk.org/jira/browse/ASTERISK-27258?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=238723#comment-238723 ]
Leon Zetekoff commented on ASTERISK-27258:
------------------------------------------
this time I've completely rebooted the VM instance and will report back later once it dies again :-(
> PJSIP issues and possible memory leaks????
> ------------------------------------------
>
> Key: ASTERISK-27258
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-27258
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: pjproject/pjsip
> Affects Versions: 14.6.0, 14.6.1
> Environment: Plus Freepbx 14.0.1.4 running on vultr.com with 2048 ram (had 1024 ram and upped it)
> Reporter: Leon Zetekoff
> Assignee: Unassigned
> Attachments: debugoutput3.txt, debugoutput4.txt, FreePBX.7z
>
>
> Potentiallly related to closed ASTERISK-25653
> While I do have sip clients on cellular right now this is all occuring in-house over wifi or wired.
> My Asterisk 14/Freepbx14 is located on vultr and now is 2048GB ram up from 1024 ram last night
> Is anyone having weird issues with PJSIP? Since I migrated from ASterisk 13/Freepbx 12 I’ve had nothing but extensions dropping off. I was running on a 1024 RAM on Vultr and upped it to 2048 ram last night and TOP is showing me free memory keeps dropping:
> {noformat}
> top - 10:21:35 up 12:16, 1 user, load average: 0.02, 0.13, 0.15
> Tasks: 107 total, 1 running, 106 sleeping, 0 stopped, 0 zombie
> %Cpu(s): 0.3 us, 0.3 sy, 0.0 ni, 99.3 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
> KiB Mem : 1883708 total, 212440 free, 778244 used, 893024 buff/cache
> KiB Swap: 2097148 total, 2094288 free, 2860 used. 790064 avail Mem
> {noformat}
> This started off as about 650000 free last night. looking at a asterisk debug I see pjsip running out of memory. Before I go over to Asterisk on this has anyone been seeing anything weird?
> Thanks leon
> some of the asterisk debug
> {noformat}
> [2017-09-06 09:45:48] ERROR[7284] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 09:45:48] ERROR[3640] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 09:45:48] ERROR[3640] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 09:45:48] ERROR[3640] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 09:45:48] ERROR[3640] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 09:45:48] ERROR[7285] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 09:45:48] ERROR[7285] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 09:45:48] ERROR[7285] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 09:45:48] ERROR[7285] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 09:45:48] ERROR[7285] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 09:45:48] ERROR[2803] pjproject: ssl0x7f0b5c0ccd40 Renegotiation failed: Not enough memory (PJ_ENOMEM)
> [2017-09-06 09:45:48] VERBOSE[2809] res_pjsip/pjsip_configuration.c: Contact 702/sips:702 at 70.44.10.180:45384;transport=TLS is now Unreachable. RTT: 0.000 msec
> [2017-09-06 09:54:06] VERBOSE[8236] res_pjsip/pjsip_configuration.c: Contact 702/sips:702 at 70.44.10.180:38964;transport=TLS has been deleted
> [2017-09-06 09:56:06] VERBOSE[8236] res_pjsip/pjsip_configuration.c: Contact 702/sips:702 at 70.44.10.180:45367;transport=TLS has been deleted
> [2017-09-06 09:59:30] VERBOSE[7602] pbx_variables.c: Setting global variable ‘SIPDOMAIN’ to ‘pbx.backwoodswireless.net’
> {noformat}
> more interesting debugs:
> {noformat}
> [2017-09-06 06:23:45] ERROR[32309] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 06:23:45] ERROR[32309] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 06:23:45] ERROR[7602] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 06:23:45] ERROR[2803] pjproject: ssl0x7f0b641d3e60 Renegotiation failed: Not enough memory (PJ_ENOMEM)
> [2017-09-06 06:23:45] VERBOSE[2809] res_pjsip/pjsip_configuration.c: Contact 702/sips:702 at 70.44.10.180:38938;transport=TLS is now Unreachable. RTT: 0.000 msec
> [2017-09-06 06:25:44] VERBOSE[7163] res_pjsip_registrar.c: Added contact ‘sips:702 at 70.44.10.180:45328;transport=TLS’ to AOR ‘702’ with expiration of 3600 seconds
> [2017-09-06 06:25:44] VERBOSE[8236] res_pjsip/pjsip_configuration.c: Contact 702/sips:702 at 70.44.10.180:45328;transport=TLS has been created
> [2017-09-06 06:25:44] ERROR[31134] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 06:25:44] ERROR[31134] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 06:25:44] ERROR[31134] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> …
> [2017-09-06 06:25:44] ERROR[8841] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 06:25:44] ERROR[7163] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 06:25:44] ERROR[2803] pjproject: ssl0x7f0b4c626b10 Renegotiation failed: Not enough memory (PJ_ENOMEM)
> [2017-09-06 06:25:44] VERBOSE[2809] res_pjsip/pjsip_configuration.c: Contact 702/sips:702 at 70.44.10.180:45328;transport=TLS is now Unreachable. RTT: 0.000 msec
> [2017-09-06 06:33:36] ERROR[2803] pjproject: sip_endpoint.c Error processing packet from 70.44.10.180:5060: Missing required header(s) (PJSIP_EMISSINGHDR) Via [code 171050]:
> SIP/2.0 400 Bad Request
> From: sip:701 at 209.222.10.59;tag=bcd2606e-5c15-492c-b6d3-0c934bb00eb4
> To: sip:701 at 70.44.10.180;tag=9ffa1a1b62bb6a06
> Call-ID: 62929999-00d7-44ed-bb3f-a43ec24ff7a9
> CSeq: 6193 NOTIFY
> User-Agent: Grandstream GXP2020 1.2.5.3
> Warning: 398 "You are not allowed to CANCEL an established dialog"
> Content-Length: 0
> – end of packet.
> [2017-09-06 06:34:03] VERBOSE[8236] res_pjsip/pjsip_configuration.c: Contact 702/sips:702 at 70.44.10.180:38926;transport=TLS has been deleted
> [2017-09-06 06:34:04] ERROR[2803] pjproject: sip_endpoint.c Error processing packet from 70.44.10.180:5066: Missing required header(s) (PJSIP_EMISSINGHDR) Via [code 171050]:
> SIP/2.0 400 Bad Request
> From: sip:702 at 209.222.10.59;tag=2c13f4fb-d808-43ef-ba65-b6455e6f978e
> To: sip:702 at 70.44.10.180;tag=86962d2d9f6b5e8b
> Call-ID: b6f21b3c-85c5-44bc-a7b7-6b8400528244
> CSeq: 4265 NOTIFY
> User-Agent: Grandstream GXP2020 1.2.5.3
> Warning: 398 "You are not allowed to CANCEL an established dialog"
> Content-Length: 0
> – end of packet.
> [2017-09-06 06:35:52] VERBOSE[2809] res_pjsip/pjsip_configuration.c: Contact 702/sips:702 at 70.44.10.180:45312;transport=TLS has been deleted
> [2017-09-06 06:36:02] VERBOSE[2767] asterisk.c: Remote UNIX connection
> [2017-09-06 06:36:02] VERBOSE[2871] asterisk.c: Remote UNIX connection disconnected
> [2017-09-06 06:36:02] VERBOSE[2767] asterisk.c: Remote UNIX connection
> [2017-09-06 06:36:02] VERBOSE[2873] asterisk.c: Remote UNIX connection disconnected
> [2017-09-06 06:36:02] VERBOSE[2767] asterisk.c: Remote UNIX connection
> [2017-09-06 06:36:02] VERBOSE[2875] asterisk.c: Remote UNIX connection disconnected
> [2017-09-06 06:38:40] VERBOSE[2809] res_pjsip/pjsip_configuration.c: Contact 701/sip:701 at 70.44.10.180:5060;transport=TCP is now Unreachable. RTT: 0.000 msec
> [2017-09-06 06:41:34] ERROR[2803] pjproject: sip_transport.c Error processing 161 bytes packet from TCP 70.44.10.180:5066 : PJSIP syntax error exception when parsing ‘’ header on line 2 col 7:
> SIP/2.0 400 Bad Request
> CSeq: User-Agent: Grandstream GXP2020 1.2.5.3
> Warning: 398 "You are not allowed to CANCEL an established dialog"
> Content-Length: 0
> – end of packet.
> [2017-09-06 06:41:34] ERROR[2803] pjproject: sip_endpoint.c Error processing packet from 70.44.10.180:5066: Missing required header(s) (PJSIP_EMISSINGHDR) Via [code 171050]:
> SIP/2.0 400 Bad Request
> From: sip:702 at 209.222.10.59;tag=c69e843a-2268-4b15-8253-752439dec7ec
> To: sip:702 at 70.44.10.180;tag=750369d3-f4fa-406f-a596-7b68de87290e
> Call-ID: cce7be3d-4c88-498f-82dd-bb3b58bac473
> CSeq: 15435 NOTIFY
> User-Agent: Grandstream GXP2020 1.2.5.3
> Warning: 398 "You are not allowed to CANCEL an established dialog"
> Content-Length: 0
> – end of packet.
> [2017-09-06 06:41:36] VERBOSE[2809] res_pjsip/pjsip_configuration.c: Contact 702/sip:702 at 70.44.10.180:5066;transport=TCP has been deleted
> [2017-09-06 07:13:45] VERBOSE[8841] res_pjsip_registrar.c: Added contact ‘sips:702 at 70.44.10.180:38939;transport=TLS’ to AOR ‘702’ with expiration of 3600 seconds
> [2017-09-06 07:13:45] VERBOSE[2809] res_pjsip/pjsip_configuration.c: Contact 702/sips:702 at 70.44.10.180:38939;transport=TLS has been created
> [2017-09-06 07:13:45] ERROR[32309] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> [2017-09-06 07:13:45] ERROR[32309] res_pjsip.c: Error 70007 ‘Not enough memory (PJ_ENOMEM)’ sending NOTIFY request to endpoint 702
> {noformat}
> Thanks leon
> jcolpAsterisk Developer
> 2h
> I haven’t seen any issues with such things and I’m aware of a few different major installs. It may be unique to your environment or what you are doing. More information would be useful. How many endpoints, subscriptions, type of transport, etc.
> wa4zlw
> 1h
> AM using PJSip for endpoints. THis all worked under Asterisk 13/fpbx 12. very weird
> basically I have three physical extensions 701-703. 703 is not connected now so just two 701 and 702. I have multiple devices talking to those extensions around the house (all grandstream and a zoiper android client which I disabled last night to debug this) On my Watchguard firewall I noticed in my traffic management window I was noticed weird sip behavior with lots of sip traffic. see this display which is no where near as bad as it was last night going over 120kbps!
> image
> image.png738x762 29.5 KB
> Usually the SIP traffic is a flat line with very low bandwidth. It was hoping all around last night.
> Also PJSIP extensions keep dropping out and I have to wait for the timers to expire. Going the debug log from last night you can see errors from the GXP2020 phone up above near the end of my original post.
> On 701 I have PJSIP set for 8 and on 702 I have it set to 6. I usually add an extra 2 count in case things get out of sync
> I have MWI subscriptions set on.
> WOuld you like to get access to the server? If so, please post me privately wa4zlw at arrl.net
> WHat else do you need? I’ve been running top all night and the free memory keeps going down pops up a bit which is what I would expect but something doesnt seem right to me
> THanks leon
> jcolpAsterisk Developer
> 1h
> I don’t provide one on one help like that. You’d need to look at the log before errors occur to see if anything looks out of the ordinary, for example is the Asterisk server under attack?
> wa4zlw
> 1h
> I also have BLF setup as well for the extensions
> no there is a firewall that freepbx runs so things are locked down.
> the log entries I entered into the ticket is whta I thought unusual and why I added them to the ticket.
> I looked at the previous ticket and it said to open a new one if you were not the original person which is what I did.
> One thing I did do is cut down from 3600 --> 900 seconds the SIP max time
> other than that I’m stumped.
> thanks leon
> wa4zlw
> 1h
> here’s another unregistration/disconnection:
> {noformat}
> [2017-09-06 11:53:57] VERBOSE[21467] asterisk.c: Remote UNIX connection
> [2017-09-06 11:53:57] VERBOSE[15247] asterisk.c: Remote UNIX connection disconnected
> [2017-09-06 11:53:57] VERBOSE[21467] asterisk.c: Remote UNIX connection
> [2017-09-06 11:53:57] VERBOSE[15249] asterisk.c: Remote UNIX connection disconnected
> [2017-09-06 11:53:57] VERBOSE[21467] asterisk.c: Remote UNIX connection
> [2017-09-06 11:53:57] VERBOSE[15251] asterisk.c: Remote UNIX connection disconnected
> [2017-09-06 12:02:41] VERBOSE[369] res_pjsip/pjsip_configuration.c: Contact 701/sip:701 at 70.44.10.180:44141;transport=TLS is now Unreachable. RTT: 0.000 msec
> [2017-09-06 12:36:03] VERBOSE[21467] asterisk.c: Remote UNIX connection
> [2017-09-06 12:36:03] VERBOSE[22779] asterisk.c: Remote UNIX connection disconnected
> [2017-09-06 12:36:03] VERBOSE[21467] asterisk.c: Remote UNIX connection
> [2017-09-06 12:36:03] VERBOSE[22781] asterisk.c: Remote UNIX connection disconnected
> [2017-09-06 12:36:03] VERBOSE[21467] asterisk.c: Remote UNIX connection
> [2017-09-06 12:36:03] VERBOSE[22783] asterisk.c: Remote UNIX connection disconnected
> {noformat}
> wa4zlw
> 1h
> more keep dropping like flies
> {noformat}
> [2017-09-06 12:36:03] VERBOSE[21467] asterisk.c: Remote UNIX connection
> [2017-09-06 12:36:03] VERBOSE[22783] asterisk.c: Remote UNIX connection disconnected
> [2017-09-06 12:49:43] VERBOSE[369] res_pjsip/pjsip_configuration.c: Contact 701/sip:701 at 70.44.10.180:44142;transport=TLS is now Unreachable. RTT: 0.000 msec
> [2017-09-06 12:49:44] VERBOSE[369] res_pjsip/pjsip_configuration.c: Contact 701/sip:701 at 70.44.10.180:44143;transport=TLS is now Unreachable. RTT: 0.000 msec
> {noformat}
> jcolpAsterisk Developer
> 33m
> That would mean that the TLS connection has dropped, or the endpoint did not respond to our OPTIONS request.
> wa4zlw
> 24m
> my latency to the pbx is like 40ms
> and this just happened
> {noformat}
> [2017-09-06 12:59:13] VERBOSE[369] res_pjsip/pjsip_configuration.c: Contact 701/sip:701 at 70.44.10.180:44142;transport=TLS has been deleted
> [2017-09-06 12:59:13] VERBOSE[369] res_pjsip/pjsip_configuration.c: Contact 701/sip:701 at 70.44.10.180:44141;transport=TLS has been deleted
> [2017-09-06 12:59:13] VERBOSE[369] res_pjsip/pjsip_configuration.c: Contact 701/sip:701 at 70.44.10.180:44143;transport=TLS has been deleted
> {noformat}
> this is going on all day up and down…what about the other errors above?
> Thanks leon
> jcolpAsterisk Developer
> 22m
> I don’t really have anything to add. You can file an issue[1] with all the information you can. There’s no timeline on when it would get looked into, and as it only seems to be impacting you it could prove difficult to figure out.
> [1] https://issues.asterisk.org/jira
--
This message was sent by Atlassian JIRA
(v6.2#6252)
More information about the asterisk-bugs
mailing list