[asterisk-bugs] [JIRA] (ASTERISK-27258) PJSIP issues and possible memory leaks????
Leon Zetekoff (JIRA)
noreply at issues.asterisk.org
Fri Sep 15 08:09:09 CDT 2017
[ https://issues.asterisk.org/jira/browse/ASTERISK-27258?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=238702#comment-238702 ]
Leon Zetekoff commented on ASTERISK-27258:
------------------------------------------
When i did an amportal stop free memory jumped up as expected but not totally to where I believe it was when rebooted
top - 08:53:43 up 14:14, 2 users, load average: 0.90, 0.53, 0.46
Tasks: 108 total, 2 running, 106 sleeping, 0 stopped, 0 zombie
%Cpu(s): 1.7 us, 1.0 sy, 0.0 ni, 97.3 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 1883708 total, 856272 free, 644384 used, 383052 buff/cache
KiB Swap: 2097148 total, 2007600 free, 89548 used. 939504 avail Mem
as I sit here and watch it lookos like linux is releasing memory slowly but is ping ponging up and down slightly. I will let things sit PRIOR to a amportal restart
when PHP goes active free memory drops and then comes back up.
just prior to amportal restart
top - 09:02:33 up 14:23, 2 users, load average: 0.01, 0.11, 0.27
Tasks: 108 total, 2 running, 106 sleeping, 0 stopped, 0 zombie
%Cpu(s): 3.3 us, 1.7 sy, 0.0 ni, 95.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 1883708 total, 854416 free, 645644 used, 383648 buff/cache
KiB Swap: 2097148 total, 2007600 free, 89548 used. 938132 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
959 asterisk 20 0 671624 51824 19152 S 3.3 2.8 3:50.91 httpd
784 mongodb 20 0 477776 8644 1996 S 0.7 0.5 1:41.68 mongod
1058 mysql 20 0 1173480 224100 5036 S 0.7 11.9 8:58.94 mysqld
1 root 20 0 43296 3196 2096 S 0.0 0.2 0:12.82 systemd
2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd
3 root 20 0 0 0 0 S 0.0 0.0 0:01.56 ksoftirqd/0
7 root rt 0 0 0 0 S 0.0 0.0 0:00.00 migration/0
8 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcu_bh
9 root 20 0 0 0 0 R 0.0 0.0 0:09.07 rcu_sched
10 root rt 0 0 0 0 S 0.0 0.0 0:00.28 watchdog/0
12 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kdevtmpfs
13 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 netns
14 root 20 0 0 0 0 S 0.0 0.0 0:00.02 khungtaskd
15 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 writeback
16 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kintegrityd
17 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 bioset
18 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kblockd
19 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 md
25 root 20 0 0 0 0 S 0.0 0.0 0:01.03 kswapd0
26 root 25 5 0 0 0 S 0.0 0.0 0:00.00 ksmd
27 root 39 19 0 0 0 S 0.0 0.0 0:01.47 khugepaged
28 root 20 0 0 0 0 S 0.0 0.0 0:00.00 fsnotify_mark
29 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 crypto
37 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kthrotld
39 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kmpath_rdacd
40 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kpsmoused
41 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 ipv6_addrconf
60 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 deferwq
92 root 20 0 0 0 0 S 0.0 0.0 0:00.38 kauditd
260 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 ata_sff
265 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kworker/u2:2
283 root 20 0 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_0
just after restart
top - 09:03:21 up 14:24, 2 users, load average: 0.90, 0.33, 0.34
Tasks: 114 total, 3 running, 111 sleeping, 0 stopped, 0 zombie
%Cpu(s): 4.4 us, 2.0 sy, 0.0 ni, 92.6 id, 1.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 1883708 total, 643112 free, 787880 used, 452716 buff/cache
KiB Swap: 2097148 total, 2007660 free, 89488 used. 792336 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
959 asterisk 20 0 671624 51824 19152 S 2.7 2.8 3:51.65 httpd
1058 mysql 20 0 1173480 224124 5056 S 1.3 11.9 8:59.44 mysqld
960 asterisk 20 0 760396 62936 28284 S 1.0 3.3 3:30.65 httpd
29359 asterisk 20 0 1613948 72296 16976 S 0.7 3.8 0:04.33 asterisk
24807 asterisk 20 0 390124 16116 9440 S 0.3 0.9 0:44.33 php
27402 root 20 0 0 0 0 S 0.3 0.0 0:00.23 kworker/0:3
30261 asterisk 20 0 1081264 49756 14380 S 0.3 2.6 0:00.87 node /var/www/h
1 root 20 0 43296 3324 2180 S 0.0 0.2 0:12.93 systemd
2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd
3 root 20 0 0 0 0 S 0.0 0.0 0:01.56 ksoftirqd/0
7 root rt 0 0 0 0 S 0.0 0.0 0:00.00 migration/0
8 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcu_bh
9 root 20 0 0 0 0 R 0.0 0.0 0:09.09 rcu_sched
10 root rt 0 0 0 0 S 0.0 0.0 0:00.28 watchdog/0
12 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kdevtmpfs
13 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 netns
14 root 20 0 0 0 0 S 0.0 0.0 0:00.02 khungtaskd
15 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 writeback
16 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kintegrityd
17 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 bioset
18 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kblockd
19 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 md
25 root 20 0 0 0 0 S 0.0 0.0 0:01.03 kswapd0
26 root 25 5 0 0 0 S 0.0 0.0 0:00.00 ksmd
27 root 39 19 0 0 0 S 0.0 0.0 0:01.47 khugepaged
28 root 20 0 0 0 0 S 0.0 0.0 0:00.00 fsnotify_mark
29 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 crypto
37 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kthrotld
39 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kmpath_rdacd
40 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kpsmoused
41 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 ipv6_addrconf
60 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 deferwq
[root at pbx ~]# amportal stop
Please wait...
!!!!amportal is depreciated. Please use fwconsole!!!!
forwarding all commands to 'fwconsole'
Running FreePBX shutdown...
Stopping RestApps Server
Stopped RestApps Server
Stopping UCP Node Server
[>---------------------------] 1 sec
Stopped UCP Node Server
Shutting down Asterisk Gracefully. Will forcefully kill after 30 seconds.
Press C to Cancel
Press N to shut down NOW
[============================] 1 sec
Wanrouter: No valid Sangoma Hardware found, if you have no Sangoma cards this is OK
Stopping DAHDi for Digium Cards
DAHDi Stopped
Queue Callback Server is not running
[root at pbx ~]# amportal restart
Please wait...
!!!!amportal is depreciated. Please use fwconsole!!!!
forwarding all commands to 'fwconsole'
Asterisk not currently running
Running FreePBX shutdown...
RestApps Server is not running
UCP Node Server is not running
Wanrouter: No valid Sangoma Hardware found, if you have no Sangoma cards this is OK
Stopping DAHDi for Digium Cards
DAHDi Stopped
Queue Callback Server is not running
Running FreePBX startup...
Wanrouter: No valid Sangoma Hardware found, if you have no Sangoma cards this is OK
Starting DAHDi for Digium Cards
DAHDi Started
Running Sysadmin Hooks
Restarting fail2ban
fail2ban Restarted
Updating License Information for 10838340
Starting Asterisk...
[============================] 2 secs
Asterisk Started
Starting RestApps Server...
Broadcast message from root at pbx.backwoodswireless.net (Fri Sep 15 09:03:00 2017):
Firewall service now starting.
[>---------------------------] 1 sec
Started RestApps Server. PID is 29654
Starting UCP Node Server...
[>---------------------------] 1 sec
Started UCP Node Server. PID is 30261
RestApps is not licensed.
Systemd shim for fail2ban running '/usr/sbin/systemctl restart fail2ban'
[root at pbx ~]#
pbx*CLI> core show taskprocessors
Processor Processed In Queue Max Depth Low water High water
app_voicemail 37 0 5 450 500
ast_msg_queue 0 0 0 450 500
CCSS_core 0 0 0 450 500
dns_system_resolver_tp 0 0 0 450 500
hep_queue_tp 0 0 0 450 500
iax2_transmit 0 0 0 450 500
pjsip/default-0000000d 13 0 1 450 500
pjsip/default-0000000e 12 0 1 450 500
pjsip/default-0000000f 10 0 1 450 500
pjsip/default-00000010 13 0 1 450 500
pjsip/default-00000011 12 0 1 450 500
pjsip/default-00000012 9 0 1 450 500
pjsip/default-00000013 11 0 1 450 500
pjsip/default-00000014 8 0 1 450 500
pjsip/distributor-00000022 3 0 1 450 500
pjsip/distributor-00000023 0 0 0 450 500
pjsip/distributor-00000024 4 0 1 450 500
pjsip/distributor-00000025 1 0 1 450 500
pjsip/distributor-00000026 7 0 2 450 500
pjsip/distributor-00000027 2 0 1 450 500
pjsip/distributor-00000028 2 0 1 450 500
pjsip/distributor-00000029 0 0 0 450 500
pjsip/distributor-0000002a 0 0 0 450 500
pjsip/distributor-0000002b 4 0 2 450 500
pjsip/distributor-0000002c 0 0 0 450 500
pjsip/distributor-0000002d 0 0 0 450 500
pjsip/distributor-0000002e 2 0 1 450 500
pjsip/distributor-0000002f 2 0 1 450 500
pjsip/distributor-00000030 0 0 0 450 500
pjsip/distributor-00000031 2 0 1 450 500
pjsip/distributor-00000032 6 0 1 450 500
pjsip/distributor-00000033 1 0 1 450 500
pjsip/distributor-00000034 4 0 2 450 500
pjsip/distributor-00000035 4 0 2 450 500
pjsip/distributor-00000036 2 0 1 450 500
pjsip/distributor-00000037 6 0 1 450 500
pjsip/distributor-00000038 4 0 2 450 500
pjsip/distributor-00000039 2 0 1 450 500
pjsip/distributor-0000003a 1 0 1 450 500
pjsip/distributor-0000003b 5 0 1 450 500
pjsip/distributor-0000003c 0 0 0 450 500
pjsip/distributor-0000003d 8 0 2 450 500
pjsip/distributor-0000003e 5 0 1 450 500
pjsip/distributor-0000003f 2 0 1 450 500
pjsip/distributor-00000040 0 0 0 450 500
pjsip/exten_state 0 0 0 450 500
pjsip/messaging 0 0 0 450 500
pjsip/mwi-00000048 58 0 2 450 500
pjsip/mwi-00000049 53 0 2 450 500
pjsip/mwi-0000004a 49 0 2 450 500
pjsip/mwi-0000004b 42 0 2 450 500
pjsip/mwi-0000004c 35 0 2 450 500
pjsip/mwi-0000004d 27 0 1 450 500
pjsip/mwi-0000004e 19 0 1 450 500
pjsip/mwi-0000004f 11 0 2 450 500
SIP 447 0 9 450 500
SIP-control 897 0 9 450 500
Sorcery 100 0 5 450 500
Sorcery-control 204 0 3 450 500
sorcery/acl-0000005f 0 0 0 450 500
sorcery/aor-0000001a 1 0 1 450 500
sorcery/asterisk-publication-00000054 0 0 0 450 500
sorcery/auth-00000015 0 0 0 450 500
sorcery/bucket-00000000 0 0 0 450 500
sorcery/contact-00000019 24 0 3 1350 1500
sorcery/contact_status-0000001b 81 0 6 1350 1500
sorcery/domain_alias-0000001c 0 0 0 450 500
sorcery/endpoint-00000016 1 0 1 450 500
sorcery/file-00000001 0 0 0 450 500
sorcery/global-0000001d 5 0 1 450 500
sorcery/identify-00000047 0 0 0 450 500
sorcery/inbound-publication-00000044 0 0 0 450 500
sorcery/log_mappings-0000000b 0 0 0 450 500
sorcery/nat_hook-00000017 0 0 0 450 500
sorcery/opus-0000000a 0 0 0 450 500
sorcery/outbound-publish-00000041 0 0 0 450 500
sorcery/registration-00000060 1 0 1 450 500
sorcery/resource_list-00000043 0 0 0 450 500
sorcery/subscription_persistence-00000042 0 0 0 450 500
sorcery/system-0000000c 0 0 0 450 500
sorcery/transport-00000018 0 0 0 450 500
stasis-core 170 0 7 450 500
stasis-core-control 354 0 7 450 500
subm:ast_bridge_topic_all-cached-00000063 1 0 1 450 500
subm:ast_channel_topic_all-00000069 2 0 1 450 500
subm:ast_channel_topic_all-0000006c 1 0 1 450 500
subm:ast_channel_topic_all-cached-00000062 5 0 2 450 500
subm:ast_channel_topic_all-cached-00000064 4 0 2 450 500
subm:ast_channel_topic_all-cached-00000068 3 0 2 450 500
subm:ast_device_state_topic-00000002 53 0 18 450 500
subm:ast_device_state_topic-00000004 52 0 18 450 500
subm:ast_device_state_topic-0000006b 3 0 2 450 500
subm:ast_parking-00000046 1 0 1 450 500
subm:ast_presence_state_topic_all-00000005 1 0 1 450 500
subm:ast_security-00000065 178 0 2 450 500
subm:ast_system-00000009 45 0 36 450 500
subm:ast_system-00000055 44 0 12 450 500
subm:ast_system-00000056 43 0 12 450 500
subm:ast_system-00000061 8 0 2 450 500
subm:cdr_engine-00000003 8 0 2 4500 5000
subm:cel_aggregation_topic-00000006 8 0 2 2700 3000
subm:endpoint_topic_all-cached-00000008 96 0 20 450 500
subm:endpoint_topic_all-cached-00000067 39 0 3 450 500
subm:manager_topic-00000007 327 0 12 2700 3000
subm:stasis_mwi_topic-00000066 34 0 1 450 500
subm:stasis_mwi_topic-0000006a 33 0 1 450 500
subp:701 at default-00000058 2 0 1 450 500
subp:701 at device-0000006f 10 0 1 450 500
subp:701 at device-0000007d 1 0 1 450 500
subp:702 at device-00000071 14 0 1 450 500
subp:702 at device-00000077 7 0 1 450 500
subp:702 at device-0000007a 4 0 1 450 500
subp:702 at device-0000007e 1 0 1 450 500
subp:703 at default-0000005a 2 0 1 450 500
subp:703 at device-00000052 1 0 1 450 500
subp:PJSIP/701-0000001e 23 0 3 450 500
subp:PJSIP/702-0000001f 25 0 3 450 500
subp:PJSIP/703-00000020 3 0 3 450 500
subp:PJSIP/dpma_endpoint-00000021 3 0 3 450 500
subp:SIP/99701-00000057 2 0 2 450 500
subp:SIP/99703-00000059 2 0 2 450 500
subp:SIP/TollFreeProxy-0000005b 4 0 2 450 500
subp:SIP/vitel-inbound-0000005c 4 0 2 450 500
subp:SIP/Vitelity-0000005d 4 0 2 450 500
subp:SIP/VoIPms-0000005e 4 0 2 450 500
125 taskprocessors
pbx*CLI>
> 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, 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