| Summary: | ASTERISK-26986: Poor high load perfomance, locks,lost rtp | ||
| Reporter: | Badalian Vyacheslav (slavon) | Labels: | |
| Date Opened: | 2017-05-05 21:58:32 | Date Closed: | 2020-01-14 11:14:13.000-0600 |
| Priority: | Minor | Regression? | |
| Status: | Closed/Complete | Components: | |
| Versions: | 13.15.0 | Frequency of Occurrence | |
| Related Issues: | |||
| Environment: | Attachments: | ||
| Description: | Have
32 core system with 256 GB memory. Running only asterisk. 500 concurrent calls to MOH - 1 avg, 100%-150% cpu.(of 3200%) running test by {noformat} sipp -sn uac -d 10000 -r 50 -s 1001 127.0.0.1 -l 2000 -p 8877 -mi 127.0.0.1 [sipp] type=friend context=sipp host=dynamic port=6000 user=sipp canreinvite=no disallow=all allow=alaw allow=ulaw transport=udp [sipp] exten => 1001,1,Answer exten => 1001,n,MusicOnHold(default) exten => 1001,n,Wait(20) exten => 1001,n,Hangup {noformat} In simple load test on sipp have many perfomnce issues: 1. FRACK! {noformat} [2017-05-06 05:48:29] ERROR[32005][C-000152e7]: astobj2.c:518 __ao2_ref: Excessive refcount 100000 reached on ao2 object 0x6080015d92f0 [2017-05-06 05:48:29] ERROR[32005][C-000152e7]: astobj2.c:518 __ao2_ref: FRACK!, Failed assertion Excessive refcount 100000 reached on ao2 object 0x6080015d92f0 (0) Got 29 backtrace records #0: [0x67e4d4] main/logger.c:1979 ast_log_backtrace() (0x67e4c0+14) #1: [0x7fe347] main/utils.c:2477 __ast_assert_failed() (0x7fe298+AF) #2: [0x496162] main/astobj2.c:437 internal_ao2_ref() #3: [0x4965d0] main/astobj2.c:519 __ao2_ref() (0x4965a2+2E) #4: [0x7a7206] main/stasis_message.c:125 stasis_message_create_full() (0x7a716d+99) #5: [0x7a73d4] main/stasis_message.c:139 stasis_message_create() (0x7a73ac+28) #6: [0x795c47] main/stasis_cache.c:789 update_create() #7: [0x795efd] main/stasis_cache.c:839 caching_topic_exec() #8: [0x783d4f] main/stasis.c:437 subscription_invoke() #9: [0x785c12] main/stasis.c:768 dispatch_message() #10: [0x786031] main/stasis.c:830 publish_msg() #11: [0x7860ca] main/stasis.c:844 stasis_publish() (0x7860a2+28) #12: [0x7a0370] main/stasis_channels.c:727 ast_channel_publish_snapshot() (0x7a014f+221) #13: [0x7a00a0] main/stasis_channels.c:701 ast_channel_stage_snapshot_done() (0x79ff4e+152) #14: [0x54c31e] main/channel.c:1004 __ast_channel_alloc_ap() #15: [0x54c4bd] main/channel.c:1019 __ast_channel_alloc() (0x54c378+145) #16: [0x7fbb94001ade] channels/chan_sip.c:8108 sip_new() #17: [0x7fbb940b5038] channels/chan_sip.c:26408 handle_request_invite() #18: [0x7fbb940c9a4e] channels/chan_sip.c:28835 handle_incoming() #19: [0x7fbb940cb1ec] channels/chan_sip.c:29044 handle_request_do() #20: [0x7fbb940ca6c4] channels/chan_sip.c:28976 sipsock_read() #21: [0x65efed] main/io.c:295 ast_io_wait() (0x65ebb1+43C) #22: [0x7fbb940cf045] channels/chan_sip.c:29610 do_monitor() #23: [0x7f7683] main/utils.c:1235 dummy_start() {noformat} 2. Periodic rtp issue ( load avg <1. asterisk cpu load 200%) {noformat} [2017-05-06 05:31:04] NOTICE[32005]: chan_sip.c:29516 check_rtp_timeout: Disconnecting call 'SIP/sipp-000080bc' for lack of RTP activity in 31 seconds {noformat} 3. Issues with taskprocessors {noformat} [2017-05-06 05:30:32] WARNING[65015][C-00008084]: taskprocessor.c:888 taskprocessor_push: The 'subm:manager_topic-00000007' task processor queue reached 3000 scheduled tasks. [2017-05-06 05:30:32] WARNING[64764][C-00007f89]: taskprocessor.c:888 taskprocessor_push: The 'subm:ast_channel_topic_all-cached-00008b4e' task processor queue reached 500 scheduled tasks. [2017-05-06 05:30:32] WARNING[64760][C-00007f85]: taskprocessor.c:888 taskprocessor_push: The 'subm:cel_aggregation_topic-00000006' task processor queue reached 3000 scheduled tasks. [2017-05-06 05:30:32] WARNING[65489]: taskprocessor.c:888 taskprocessor_push: The 'subp:SIP/sipp-00008b48' task processor queue reached 500 scheduled tasks. [2017-05-06 05:30:32] WARNING[64938][C-00008037]: taskprocessor.c:888 taskprocessor_push: The 'subm:cdr_engine-00000003' task processor queue reached 5000 scheduled tasks. m1-asterisk01t*CLI> core show taskprocessors Processor Processed In Queue Max Depth Low water High water app_voicemail 0 0 0 450 500 ast_msg_queue 0 0 0 450 500 CCSS_core 0 0 0 450 500 hep_queue_tp 0 0 0 450 500 iax2_transmit 0 0 0 450 500 pjsip/default-0000000c 4 0 1 450 500 pjsip/default-0000000d 3 0 1 450 500 pjsip/default-0000000e 3 0 1 450 500 pjsip/default-0000000f 3 0 1 450 500 pjsip/default-00000010 3 0 1 450 500 pjsip/default-00000011 3 0 1 450 500 pjsip/default-00000012 3 0 1 450 500 pjsip/default-00000013 3 0 1 450 500 pjsip/distributor-0000001d 0 0 0 450 500 pjsip/distributor-0000001e 0 0 0 450 500 pjsip/distributor-0000001f 0 0 0 450 500 pjsip/distributor-00000020 0 0 0 450 500 pjsip/distributor-00000021 0 0 0 450 500 pjsip/distributor-00000022 0 0 0 450 500 pjsip/distributor-00000023 0 0 0 450 500 pjsip/distributor-00000024 0 0 0 450 500 pjsip/distributor-00000025 0 0 0 450 500 pjsip/distributor-00000026 0 0 0 450 500 pjsip/distributor-00000027 0 0 0 450 500 pjsip/distributor-00000028 0 0 0 450 500 pjsip/distributor-00000029 0 0 0 450 500 pjsip/distributor-0000002a 0 0 0 450 500 pjsip/distributor-0000002b 0 0 0 450 500 pjsip/distributor-0000002c 0 0 0 450 500 pjsip/distributor-0000002d 0 0 0 450 500 pjsip/distributor-0000002e 0 0 0 450 500 pjsip/distributor-0000002f 0 0 0 450 500 pjsip/distributor-00000030 0 0 0 450 500 pjsip/distributor-00000031 0 0 0 450 500 pjsip/distributor-00000032 0 0 0 450 500 pjsip/distributor-00000033 0 0 0 450 500 pjsip/distributor-00000034 0 0 0 450 500 pjsip/distributor-00000035 0 0 0 450 500 pjsip/distributor-00000036 0 0 0 450 500 pjsip/distributor-00000037 0 0 0 450 500 pjsip/distributor-00000038 0 0 0 450 500 pjsip/distributor-00000039 0 0 0 450 500 pjsip/distributor-0000003a 0 0 0 450 500 pjsip/distributor-0000003b 0 0 0 450 500 pjsip/messaging 0 0 0 450 500 pjsip/mwi-00000042 0 0 0 450 500 pjsip/mwi-00000043 0 0 0 450 500 pjsip/mwi-00000044 0 0 0 450 500 pjsip/mwi-00000045 0 0 0 450 500 pjsip/mwi-00000046 0 0 0 450 500 pjsip/mwi-00000047 0 0 0 450 500 pjsip/mwi-00000048 0 0 0 450 500 pjsip/mwi-00000049 0 0 0 450 500 SIP 25 0 1 450 500 SIP-control 56 0 2 450 500 Sorcery 10 0 4 450 500 Sorcery-control 25 0 4 450 500 sorcery/acl-00008b49 0 0 0 450 500 sorcery/aor-00000019 1 0 1 450 500 sorcery/asterisk-publication-0000004b 0 0 0 450 500 sorcery/auth-00000014 0 0 0 450 500 sorcery/bucket-00000000 0 0 0 450 500 sorcery/contact-00000018 1 0 1 1350 1500 sorcery/contact_status-0000001a 1 0 1 1350 1500 sorcery/domain_alias-0000001b 0 0 0 450 500 sorcery/endpoint-00000015 1 0 1 450 500 sorcery/file-00000001 0 0 0 450 500 sorcery/global-0000001c 5 0 1 450 500 sorcery/identify-00000041 0 0 0 450 500 sorcery/inbound-publication-0000003f 0 0 0 450 500 sorcery/log_mappings-0000000a 0 0 0 450 500 sorcery/nat_hook-00000016 0 0 0 450 500 sorcery/outbound-publish-0000003c 0 0 0 450 500 sorcery/phoneprov-00008b4a 0 0 0 450 500 sorcery/registration-00008b4b 1 0 1 450 500 sorcery/resource_list-0000003e 0 0 0 450 500 sorcery/subscription_persistence-0000003d 0 0 0 450 500 sorcery/system-0000000b 0 0 0 450 500 sorcery/transport-00000017 0 0 0 450 500 stasis-core 2023100 1 9 450 500 stasis-core-control 4046215 1 17 450 500 subm:ast_bridge_topic_all-cached-00008b4d 1 0 1 450 500 subm:ast_channel_topic_all-00008b51 1369195 0 258 450 500 subm:ast_channel_topic_all-cached-00008b4e 1986136 0 556 450 500 subm:ast_device_state_topic-00000002 205492 0 4 450 500 subm:ast_device_state_topic-00000004 205491 0 4 450 500 subm:ast_device_state_topic-00008b50 205484 0 14 450 500 subm:ast_presence_state_topic_all-00000005 1 0 1 450 500 subm:ast_security-00008b4f 2 0 1 450 500 subm:ast_system-00000009 35 0 29 450 500 subm:ast_system-0000004c 34 0 1 450 500 subm:ast_system-0000004d 33 0 1 450 500 subm:ast_system-00008b4c 1 0 1 450 500 subm:cdr_engine-00000003 1986136 1 7438 4500 5000 subm:cel_aggregation_topic-00000006 1986134 3 7475 2700 3000 subm:endpoint_topic_all-cached-00000008 2366516 0 458 450 500 subm:manager_topic-00000007 2042433 217520 218830 2700 3000 ... subp:SIP/sipp-00008b48 2124754 0 6451 450 500 {noformat} | ||
| Comments: | By: Asterisk Team (asteriskteam) 2017-05-05 21:58:33.039-0500 Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution. A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report. Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process]. By: Richard Mudgett (rmudgett) 2017-05-08 09:49:56.074-0500 See my blog post about taskprocessors [1]. I see that you have CDR and CEL enabled. Do you need either? If not then do not enable them as you had both of them hit the taskprocessor high water mark warnings. The CDR implementation requires a lot more CPU than CEL. [1] http://blogs.asterisk.org/2016/07/13/asterisk-task-processor-queue-size-warnings/ By: Asterisk Team (asteriskteam) 2017-05-24 12:00:02.047-0500 Suspended due to lack of activity. This issue will be automatically re-opened if the reporter posts a comment. If you are not the reporter and would like this re-opened please create a new issue instead. If the new issue is related to this one a link will be created during the triage process. Further information on issue tracker usage can be found in the Asterisk Issue Guidlines [1]. [1] https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines | ||