[asterisk-bugs] [JIRA] (ASTERISK-28999) pjsip / sorcery / ao2: Large refcounts (FRACKs) on reload of large pjsip.conf configuration

Wed Jul 22 04:01:27 CDT 2020

     [ https://issues.asterisk.org/jira/browse/ASTERISK-28999?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Joshua C. Colp updated ASTERISK-28999:
--------------------------------------

    Component/s: Resources/res_pjsip
                 Core/Stasis
                 Core/General

> pjsip / sorcery / ao2: Large refcounts (FRACKs) on reload of large pjsip.conf configuration
> -------------------------------------------------------------------------------------------
>
>                 Key: ASTERISK-28999
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-28999
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Core/General, Core/Sorcery, Core/Stasis, Resources/res_pjsip
>    Affects Versions: 16.11.1
>         Environment: Ubuntu 18.04.4 LTS, Asterisk 16.11.1
>            Reporter: Gregory Massel
>            Severity: Minor
>
> I have an extremely large pjsip.conf (~24,000 endpoints) all being loaded directly from configuration files (no realtime).
> Every single time I start Astersik up or do a "module reload res_pjsip.so", aside from it being extremely slow (over five minutes) to process, it always results in FRACKs.
> e.g. On startup:
> [Jul 21 03:44:23] ERROR[11916] stasis.c: Excessive refcount 100000 reached on ao2 object 0x563b78882c30
> [Jul 21 03:44:23] ERROR[11916] stasis.c: FRACK!, Failed assertion Excessive refcount 100000 reached on ao2 object 0x563b78882c30 (0)
> [Jul 21 03:44:23] ERROR[11916] : Got 23 backtrace records
> # 0: [0x563b77a0d1fe] asterisk utils.c:2404 __ast_assert_failed()
> # 1: [0x563b77880221] asterisk astobj2.c:588 __ao2_ref()
> # 2: [0x563b779ceb22] asterisk stasis.c:541 link_topic_proxy()
> # 3: [0x563b779ceffc] asterisk stasis.c:594 stasis_topic_create_with_detail()
> # 4: [0x563b779cf0f7] asterisk stasis.c:614 stasis_topic_create()
> # 5: [0x563b779d1f6c] asterisk stasis.c:1901 stasis_topic_pool_get_topic()
> # 6: [0x563b77953961] asterisk mwi.c:103 ast_mwi_topic()
> # 7: [0x563b77953ea6] asterisk mwi.c:215 ast_publish_mwi_state_full()
> # 8: [0x7fe6f20208cc] app_voicemail.so app_voicemail.c:8219 queue_mwi_event()
> # 9: [0x7fe6f2030173] app_voicemail.so app_voicemail.c:12568 append_mailbox()
> #10: [0x7fe6f2034083] app_voicemail.so app_voicemail.c:13934 load_users()
> #11: [0x7fe6f20377f8] app_voicemail.so app_voicemail.c:14603 actual_load_config()
> #12: [0x7fe6f2033b1d] app_voicemail.so app_voicemail.c:13830 load_config()
> #13: [0x7fe6f2038658] app_voicemail.so app_voicemail.c:15437 load_module()
> #14: [0x563b7793fa92] asterisk loader.c:1711 start_resource()
> #15: [0x563b7794053d] asterisk loader.c:1887 start_resource_attempt()
> #16: [0x563b77940f22] asterisk loader.c:1984 start_resource_list()
> #17: [0x563b77941ccf] asterisk loader.c:2166 load_resource_list()
> #18: [0x563b77942724] asterisk loader.c:2379 load_modules()
> #19: [0x563b7787e711] asterisk asterisk.c:4152 asterisk_daemon()
> #20: [0x563b7787dbda] asterisk asterisk.c:3924 main()
> #21: [0x7fe7545d2b97] libc.so.6 libc-start.c:344 __libc_start_main()
> #22: asterisk <unknown>()
> e.g. On reload:
> [Jul 21 08:33:12] VERBOSE[3902] loader.c: Reloading module 'res_pjsip.so' (Basic SIP resource)
> [..time passes and lots of unrelated logs..]
> [Jul 21 08:35:39] ERROR[5408][C-0000281f] format_cap.c: Excessive refcount 100000 reached on ao2 object 0x563b7888d528
> [Jul 21 08:35:39] ERROR[5408][C-0000281f] format_cap.c: FRACK!, Failed assertion Excessive refcount 100000 reached on ao2 object 0x563b7888d528 (0)
> [Jul 21 08:35:39] ERROR[872][C-00002262] frame.c: Excessive refcount 100000 reached on ao2 object 0x563b7888d528
> [Jul 21 08:35:39] ERROR[872][C-00002262] frame.c: FRACK!, Failed assertion Excessive refcount 100000 reached on ao2 object 0x563b7888d528 (0)
> [Jul 21 08:35:39] ERROR[3949][C-0000263d] frame.c: Excessive refcount 100000 reached on ao2 object 0x563b7888d528
> [Jul 21 08:35:39] ERROR[3949][C-0000263d] frame.c: FRACK!, Failed assertion Excessive refcount 100000 reached on ao2 object 0x563b7888d528 (0)
> [Jul 21 08:35:39] ERROR[22121] : Got 26 backtrace records
> # 0: [0x563b77a0d1fe] asterisk utils.c:2404 __ast_assert_failed()
> # 1: [0x563b77880221] asterisk astobj2.c:588 __ao2_ref()
> # 2: [0x563b7792b5e0] asterisk format_cap.c:211 __ast_format_cap_append()
> # 3: [0x563b7792bed0] asterisk format_cap.c:379 ast_format_cap_update_by_allow_disallow()
> # 4: [0x563b778fad86] asterisk config_options.c:1515 codec_handler_fn()
> # 5: [0x563b778f834d] asterisk config_options.c:797 aco_process_var()
> # 6: [0x563b779ca316] asterisk sorcery.c:1648 ast_sorcery_objectset_apply()
> # 7: [0x7fe6ddcb8b3f] res_sorcery_config.so res_sorcery_config.c:408 sorcery_config_internal_load()
> # 8: [0x7fe6ddcb8e4c] res_sorcery_config.so res_sorcery_config.c:448 sorcery_config_reload()
> # 9: [0x563b779c8528] asterisk sorcery.c:1272 sorcery_wizard_load()
> #10: [0x563b779c8ae4] asterisk sorcery.c:1354 sorcery_object_load()
> #11: [0x563b77882050] asterisk astobj2_container.c:328 internal_ao2_traverse()
> #12: [0x563b77882340] asterisk astobj2_container.c:414 __ao2_callback()
> #13: [0x563b779c9278] asterisk sorcery.c:1415 ast_sorcery_reload()
> #14: [0x7fe6da9de970] res_pjsip.so pjsip_configuration.c:2058 ast_res_pjsip_reload_configuration()
> #15: [0x7fe6da9b6e60] res_pjsip.so res_pjsip.c:5095 reload_configuration_task()
> #16: [0x7fe6da9b5bfb] res_pjsip.so res_pjsip.c:4611 sync_task()
> #17: [0x563b779f6836] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
> #18: [0x563b77a00b4c] asterisk threadpool.c:1354 execute_tasks()
> #19: [0x563b779f6836] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
> #20: [0x563b779fe515] asterisk threadpool.c:367 threadpool_execute()
> #21: [0x563b77a00315] asterisk threadpool.c:1137 worker_active()
> #22: [0x563b77a00085] asterisk threadpool.c:1057 worker_start()
> #23: [0x563b77a0a05e] asterisk utils.c:1249 dummy_start()
> #24: [0x7fe7554e16db] libpthread.so.0 pthread_create.c:463 start_thread()
> #25: [0x7fe7546d2a3f] libc.so.6 clone.S:97 clone()
> [Jul 21 08:35:39] ERROR[4141][C-00002698] frame.c: Excessive refcount 100000 reached on ao2 object 0x563b7888d528
> [Jul 21 08:35:39] ERROR[4141][C-00002698] frame.c: FRACK!, Failed assertion Excessive refcount 100000 reached on ao2 object 0x563b7888d528 (0)
> [..more unrelated logs..]
> [Jul 21 08:35:40] ERROR[872][C-00002262] : Got 14 backtrace records
> # 0: [0x563b77a0d1fe] asterisk utils.c:2404 __ast_assert_failed()
> # 1: [0x563b77880221] asterisk astobj2.c:588 __ao2_ref()
> # 2: [0x563b7792e7ae] asterisk frame.c:349 ast_frdup()
> # 3: [0x563b778ac53a] asterisk bridge_channel.c:1046 ast_bridge_channel_queue_frame()
> # 4: [0x563b778ac8cb] asterisk bridge_channel.c:1104 ast_bridge_queue_everyone_else()
> # 5: [0x7fe6e7ed123d] bridge_simple.so bridge_simple.c:174 simple_bridge_write()
> # 6: [0x563b778ab8ee] asterisk bridge_channel.c:696 bridge_channel_write_frame()
> # 7: [0x563b778b0fdf] asterisk bridge_channel.c:2633 bridge_handle_trip()
> # 8: [0x563b778b141f] asterisk bridge_channel.c:2768 bridge_channel_wait()
> # 9: [0x563b778b1c8b] asterisk bridge_channel.c:2917 bridge_channel_internal_join()
> #10: [0x563b778935cb] asterisk bridge.c:1819 bridge_channel_ind_thread()
> #11: [0x563b77a0a05e] asterisk utils.c:1249 dummy_start()
> #12: [0x7fe7554e16db] libpthread.so.0 pthread_create.c:463 start_thread()
> #13: [0x7fe7546d2a3f] libc.so.6 clone.S:97 clone()
> [Jul 21 08:35:40] VERBOSE[24864] pbx_variables.c: Setting global variable 'SIPDOMAIN' to '196.216.192.8'
> [Jul 21 08:35:40] VERBOSE[4064] pbx_variables.c: Setting global variable 'SIPDOMAIN' to 'vpbx0.switchtel.co.za'
> [Jul 21 08:35:40] ERROR[5408][C-0000281f] : Got 20 backtrace records
> # 0: [0x563b77a0d1fe] asterisk utils.c:2404 __ast_assert_failed()
> # 1: [0x563b77880221] asterisk astobj2.c:588 __ao2_ref()
> # 2: [0x563b7792b5e0] asterisk format_cap.c:211 __ast_format_cap_append()
> # 3: [0x563b7792b901] asterisk format_cap.c:279 ast_format_cap_append_from_cap()
> # 4: [0x563b779ee74a] asterisk stream.c:628 ast_format_cap_from_stream_topology()
> # 5: [0x7fe6d525672f] chan_pjsip.so chan_pjsip.c:524 compatible_formats_exist()
> # 6: [0x7fe6d5256ae7] chan_pjsip.so chan_pjsip.c:573 chan_pjsip_new()
> # 7: [0x7fe6d525d4c4] chan_pjsip.so chan_pjsip.c:2712 chan_pjsip_request_with_stream_topology()
> # 8: [0x563b778d1834] asterisk channel.c:6253 request_channel()
> # 9: [0x563b778d1f39] asterisk channel.c:6346 ast_request_with_stream_topology()
> #10: [0x7fe6e0758d81] app_dial.so app_dial.c:2570 dial_exec_full()
> #11: [0x7fe6e075cb41] app_dial.so app_dial.c:3324 dial_exec()
> #12: [0x563b7797811f] asterisk pbx_app.c:492 pbx_exec()
> #13: [0x563b77961a1f] asterisk pbx.c:2947 pbx_extension_helper()
> #14: [0x563b77965eb7] asterisk pbx.c:4197 ast_spawn_extension()
> #15: [0x563b77966c6b] asterisk pbx.c:4371 __ast_pbx_run()
> #16: [0x563b779685e8] asterisk pbx.c:4696 pbx_thread()
> #17: [0x563b77a0a05e] asterisk utils.c:1249 dummy_start()
> #18: [0x7fe7554e16db] libpthread.so.0 pthread_create.c:463 start_thread()
> #19: [0x7fe7546d2a3f] libc.so.6 clone.S:97 clone()
> [Jul 21 08:35:40] ERROR[3949][C-0000263d] : Got 23 backtrace records
> # 0: [0x563b77a0d1fe] asterisk utils.c:2404 __ast_assert_failed()
> # 1: [0x563b77880221] asterisk astobj2.c:588 __ao2_ref()
> # 2: [0x563b7792e7ae] asterisk frame.c:349 ast_frdup()
> # 3: [0x563b778ac53a] asterisk bridge_channel.c:1046 ast_bridge_channel_queue_frame()
> # 4: [0x563b778ac8cb] asterisk bridge_channel.c:1104 ast_bridge_queue_everyone_else()
> # 5: [0x7fe6e7ed123d] bridge_simple.so bridge_simple.c:174 simple_bridge_write()
> # 6: [0x563b778ab8ee] asterisk bridge_channel.c:696 bridge_channel_write_frame()
> # 7: [0x563b778b0fdf] asterisk bridge_channel.c:2633 bridge_handle_trip()
> # 8: [0x563b778b141f] asterisk bridge_channel.c:2768 bridge_channel_wait()
> # 9: [0x563b778b1c8b] asterisk bridge_channel.c:2917 bridge_channel_internal_join()
> #10: [0x563b7789330f] asterisk bridge.c:1749 ast_bridge_join()
> #11: [0x563b77a50313] asterisk features.c:680 ast_bridge_call_with_flags()
> #12: [0x563b77a50403] asterisk features.c:711 ast_bridge_call()
> #13: [0x7fe6e075c726] app_dial.so app_dial.c:3267 dial_exec_full()
> #14: [0x7fe6e075cb41] app_dial.so app_dial.c:3324 dial_exec()
> #15: [0x563b7797811f] asterisk pbx_app.c:492 pbx_exec()
> #16: [0x563b77961a1f] asterisk pbx.c:2947 pbx_extension_helper()
> #17: [0x563b77965eb7] asterisk pbx.c:4197 ast_spawn_extension()
> #18: [0x563b77966c6b] asterisk pbx.c:4371 __ast_pbx_run()
> #19: [0x563b779685e8] asterisk pbx.c:4696 pbx_thread()
> #20: [0x563b77a0a05e] asterisk utils.c:1249 dummy_start()
> #21: [0x7fe7554e16db] libpthread.so.0 pthread_create.c:463 start_thread()
> #22: [0x7fe7546d2a3f] libc.so.6 clone.S:97 clone()
> [..more unrelated logs..]
> [Jul 21 08:35:40] ERROR[4141][C-00002698] : Got 23 backtrace records
> # 0: [0x563b77a0d1fe] asterisk utils.c:2404 __ast_assert_failed()
> # 1: [0x563b77880221] asterisk astobj2.c:588 __ao2_ref()
> # 2: [0x563b7792e7ae] asterisk frame.c:349 ast_frdup()
> # 3: [0x563b778ac53a] asterisk bridge_channel.c:1046 ast_bridge_channel_queue_frame()
> # 4: [0x563b778ac8cb] asterisk bridge_channel.c:1104 ast_bridge_queue_everyone_else()
> # 5: [0x7fe6e7ed123d] bridge_simple.so bridge_simple.c:174 simple_bridge_write()
> # 6: [0x563b778ab8ee] asterisk bridge_channel.c:696 bridge_channel_write_frame()
> # 7: [0x563b778b0fdf] asterisk bridge_channel.c:2633 bridge_handle_trip()
> # 8: [0x563b778b141f] asterisk bridge_channel.c:2768 bridge_channel_wait()
> # 9: [0x563b778b1c8b] asterisk bridge_channel.c:2917 bridge_channel_internal_join()
> #10: [0x563b7789330f] asterisk bridge.c:1749 ast_bridge_join()
> #11: [0x563b77a50313] asterisk features.c:680 ast_bridge_call_with_flags()
> #12: [0x563b77a50403] asterisk features.c:711 ast_bridge_call()
> #13: [0x7fe6e075c726] app_dial.so app_dial.c:3267 dial_exec_full()
> #14: [0x7fe6e075cb41] app_dial.so app_dial.c:3324 dial_exec()
> #15: [0x563b7797811f] asterisk pbx_app.c:492 pbx_exec()
> #16: [0x563b77961a1f] asterisk pbx.c:2947 pbx_extension_helper()
> #17: [0x563b77965eb7] asterisk pbx.c:4197 ast_spawn_extension()
> #18: [0x563b77966c6b] asterisk pbx.c:4371 __ast_pbx_run()
> #19: [0x563b779685e8] asterisk pbx.c:4696 pbx_thread()
> #20: [0x563b77a0a05e] asterisk utils.c:1249 dummy_start()
> #21: [0x7fe7554e16db] libpthread.so.0 pthread_create.c:463 start_thread()
> #22: [0x7fe7546d2a3f] libc.so.6 clone.S:97 clone()
> [..more unrelated logs..]
> [Jul 21 08:38:43] NOTICE[22121] sorcery.c: Type 'system' is not reloadable, maintaining previous values
> These do NOT crash Asterisk, however, if Asterisk is doing a full start-up, it is unresponsive for at least five minutes. During just a pjsip reload, it remains responsive.


--
This message was sent by Atlassian JIRA
(v6.2#6252)