[asterisk-bugs] [JIRA] (ASTERISK-29523) cdr.c: FRACK!, Failed assertion user_data is NULL (0)

Wed Jul 28 10:29:33 CDT 2021

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

Kevin Harwell updated ASTERISK-29523:
-------------------------------------

    Description: 
In our daily pre-production regression, the following FRACK messages showed up in the log that seem to be related to a Snoop channel leaving a bridge. 

Running core dump taken and will send under separate cover. 
{noformat}
[Jul 16 09:56:33] ERROR[26751] cdr.c: FRACK!, Failed assertion user_data is NULL (0)
[Jul 16 09:56:33] DEBUG[3945][C-00000011] res_rtp_asterisk.c: (0x7f28a0187df0) RTCP got report of 100 bytes from 192.168.1.218:17095
[Jul 16 09:56:33] DEBUG[2528] res_rtp_asterisk.c: (0x7f287c03faf0) RTCP got report of 56 bytes from 192.168.10.69:59300
[Jul 16 09:56:33] ERROR[26751] : Got 11 backtrace records
# 0: [0x56423e1d5ef3] asterisk utils.c:2454 __ast_assert_failed()
# 1: [0x56423e05d6b6] asterisk astobj2.c:298 __ao2_unlock()
# 2: [0x56423e1effd6] asterisk cdr.c:2336 handle_channel_snapshot_update_message()
# 3: [0x56423e1a99b6] asterisk stasis_message_router.c:202 router_dispatch()
# 4: [0x56423e195f57] asterisk stasis.c:1266 dispatch_exec_async()
# 5: [0x56423e1bf6f6] asterisk taskprocessor.c:370 tps_task_free()
# 6: [inlined] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
# 7: [inlined] asterisk taskprocessor.c:209 default_tps_processing_function()
# 8: [0x56423e1d136f] asterisk utils.c:1301 dummy_start()
# 9: [0x7f29512db6db] libpthread.so.0 pthread_create.c:463 start_thread()
#10: [0x7f29504cca3f] libc.so.6 clone.S:97 clone()

[Jul 16 09:56:33] ERROR[26751] cdr.c: FRACK!, Failed assertion user_data is NULL (0)
[Jul 16 09:56:33] ERROR[26751] : Got 12 backtrace records
# 0: [0x56423e1d5ef3] asterisk utils.c:2454 __ast_assert_failed()
# 1: [0x56423e05dc57] asterisk astobj2.c:516 __ao2_ref()
# 2: [0x56423e1e99fb] asterisk cdr.c:981 cdr_all_unlink()
# 3: [0x56423e1effde] asterisk cdr.c:2337 handle_channel_snapshot_update_message()
# 4: [0x56423e1a99b6] asterisk stasis_message_router.c:202 router_dispatch()
# 5: [0x56423e195f57] asterisk stasis.c:1266 dispatch_exec_async()
# 6: [0x56423e1bf6f6] asterisk taskprocessor.c:370 tps_task_free()
# 7: [inlined] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
# 8: [inlined] asterisk taskprocessor.c:209 default_tps_processing_function()
# 9: [0x56423e1d136f] asterisk utils.c:1301 dummy_start()
#10: [0x7f29512db6db] libpthread.so.0 pthread_create.c:463 start_thread()
#11: [0x7f29504cca3f] libc.so.6 clone.S:97 clone()

[Jul 16 09:56:33] ERROR[26751] cdr.c: FRACK!, Failed assertion user_data is NULL (0)
[Jul 16 09:56:33] DEBUG[3918] res_pjsip/pjsip_distributor.c: No dialog serializer for Response msg 200/MESSAGE/cseq=41591 (rdata0x7f28a00c43b8).  Using request transaction as basis.
[Jul 16 09:56:33] DEBUG[3918] res_pjsip/pjsip_distributor.c: Found transaction tsx0x7f29381a0968 for Response msg 200/MESSAGE/cseq=41591 (rdata0x7f28a00c43b8).
[Jul 16 09:56:33] DEBUG[3918] res_pjsip/pjsip_distributor.c: Found serializer pjsip/messaging on transaction tsx0x7f29381a0968
[Jul 16 09:56:33] DEBUG[3918] res_pjsip.c: 0x7f28a00c0690: PJSIP tsx response received
[Jul 16 09:56:33] DEBUG[3918] res_pjsip.c: 0x7f28a00c0690: Callbacks executed
[Jul 16 09:56:33] DEBUG[3918] res_pjsip.c: 0x7f28a00c0690: wrapper destroyed
[Jul 16 09:56:33] ERROR[26751] : Got 11 backtrace records
# 0: [0x56423e1d5ef3] asterisk utils.c:2454 __ast_assert_failed()
# 1: [0x56423e05dc57] asterisk astobj2.c:516 __ao2_ref()
# 2: [0x56423e1effde] asterisk cdr.c:2337 handle_channel_snapshot_update_message()
# 3: [0x56423e1a99b6] asterisk stasis_message_router.c:202 router_dispatch()
# 4: [0x56423e195f57] asterisk stasis.c:1266 dispatch_exec_async()
# 5: [0x56423e1bf6f6] asterisk taskprocessor.c:370 tps_task_free()
# 6: [inlined] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
# 7: [inlined] asterisk taskprocessor.c:209 default_tps_processing_function()
# 8: [0x56423e1d136f] asterisk utils.c:1301 dummy_start()
# 9: [0x7f29512db6db] libpthread.so.0 pthread_create.c:463 start_thread()
#10: [0x7f29504cca3f] libc.so.6 clone.S:97 clone()

[Jul 16 09:56:33] ERROR[26751] cdr.c: FRACK!, Failed assertion user_data is NULL (0)
[Jul 16 09:56:33] ERROR[26751] : Got 12 backtrace records
# 0: [0x56423e1d5ef3] asterisk utils.c:2454 __ast_assert_failed()
# 1: [0x56423e05d2e4] asterisk astobj2.c:212 log_bad_ao2()
# 2: [0x56423e060eba] asterisk astobj2_container.c:178 __ao2_unlink()
# 3: [0x56423e1f0004] asterisk cdr.c:2341 handle_channel_snapshot_update_message()
# 4: [0x56423e1a99b6] asterisk stasis_message_router.c:202 router_dispatch()
# 5: [0x56423e195f57] asterisk stasis.c:1266 dispatch_exec_async()
# 6: [0x56423e1bf6f6] asterisk taskprocessor.c:370 tps_task_free()
# 7: [inlined] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
# 8: [inlined] asterisk taskprocessor.c:209 default_tps_processing_function()
# 9: [0x56423e1d136f] asterisk utils.c:1301 dummy_start()
#10: [0x7f29512db6db] libpthread.so.0 pthread_create.c:463 start_thread()
#11: [0x7f29504cca3f] libc.so.6 clone.S:97 clone()

[Jul 16 09:56:33] DEBUG[26751] cdr.c: Finalized CDR for Snoop/SKTAOTP.jdote-00000006 - start 1626443793.404317 answer 1626443793.404317 end 1626443793.424157 dur 0.019 bill 0.019 dispo ANSWERED
[Jul 16 09:56:33] DEBUG[2528] res_rtp_asterisk.c: (0x7f287c03faf0) RTCP got report of 8 bytes from 192.168.10.69:59300
{noformat}

  was:
In our daily pre-production regression, the following FRACK messages showed up in the log that seem to be related to a Snoop channel leaving a bridge. 

Running core dump taken and will send under separate cover. 

[Jul 16 09:56:33] ERROR[26751] cdr.c: FRACK!, Failed assertion user_data is NULL (0)
[Jul 16 09:56:33] DEBUG[3945][C-00000011] res_rtp_asterisk.c: (0x7f28a0187df0) RTCP got report of 100 bytes from 192.168.1.218:17095
[Jul 16 09:56:33] DEBUG[2528] res_rtp_asterisk.c: (0x7f287c03faf0) RTCP got report of 56 bytes from 192.168.10.69:59300
[Jul 16 09:56:33] ERROR[26751] : Got 11 backtrace records
# 0: [0x56423e1d5ef3] asterisk utils.c:2454 __ast_assert_failed()
# 1: [0x56423e05d6b6] asterisk astobj2.c:298 __ao2_unlock()
# 2: [0x56423e1effd6] asterisk cdr.c:2336 handle_channel_snapshot_update_message()
# 3: [0x56423e1a99b6] asterisk stasis_message_router.c:202 router_dispatch()
# 4: [0x56423e195f57] asterisk stasis.c:1266 dispatch_exec_async()
# 5: [0x56423e1bf6f6] asterisk taskprocessor.c:370 tps_task_free()
# 6: [inlined] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
# 7: [inlined] asterisk taskprocessor.c:209 default_tps_processing_function()
# 8: [0x56423e1d136f] asterisk utils.c:1301 dummy_start()
# 9: [0x7f29512db6db] libpthread.so.0 pthread_create.c:463 start_thread()
#10: [0x7f29504cca3f] libc.so.6 clone.S:97 clone()

[Jul 16 09:56:33] ERROR[26751] cdr.c: FRACK!, Failed assertion user_data is NULL (0)
[Jul 16 09:56:33] ERROR[26751] : Got 12 backtrace records
# 0: [0x56423e1d5ef3] asterisk utils.c:2454 __ast_assert_failed()
# 1: [0x56423e05dc57] asterisk astobj2.c:516 __ao2_ref()
# 2: [0x56423e1e99fb] asterisk cdr.c:981 cdr_all_unlink()
# 3: [0x56423e1effde] asterisk cdr.c:2337 handle_channel_snapshot_update_message()
# 4: [0x56423e1a99b6] asterisk stasis_message_router.c:202 router_dispatch()
# 5: [0x56423e195f57] asterisk stasis.c:1266 dispatch_exec_async()
# 6: [0x56423e1bf6f6] asterisk taskprocessor.c:370 tps_task_free()
# 7: [inlined] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
# 8: [inlined] asterisk taskprocessor.c:209 default_tps_processing_function()
# 9: [0x56423e1d136f] asterisk utils.c:1301 dummy_start()
#10: [0x7f29512db6db] libpthread.so.0 pthread_create.c:463 start_thread()
#11: [0x7f29504cca3f] libc.so.6 clone.S:97 clone()

[Jul 16 09:56:33] ERROR[26751] cdr.c: FRACK!, Failed assertion user_data is NULL (0)
[Jul 16 09:56:33] DEBUG[3918] res_pjsip/pjsip_distributor.c: No dialog serializer for Response msg 200/MESSAGE/cseq=41591 (rdata0x7f28a00c43b8).  Using request transaction as basis.
[Jul 16 09:56:33] DEBUG[3918] res_pjsip/pjsip_distributor.c: Found transaction tsx0x7f29381a0968 for Response msg 200/MESSAGE/cseq=41591 (rdata0x7f28a00c43b8).
[Jul 16 09:56:33] DEBUG[3918] res_pjsip/pjsip_distributor.c: Found serializer pjsip/messaging on transaction tsx0x7f29381a0968
[Jul 16 09:56:33] DEBUG[3918] res_pjsip.c: 0x7f28a00c0690: PJSIP tsx response received
[Jul 16 09:56:33] DEBUG[3918] res_pjsip.c: 0x7f28a00c0690: Callbacks executed
[Jul 16 09:56:33] DEBUG[3918] res_pjsip.c: 0x7f28a00c0690: wrapper destroyed
[Jul 16 09:56:33] ERROR[26751] : Got 11 backtrace records
# 0: [0x56423e1d5ef3] asterisk utils.c:2454 __ast_assert_failed()
# 1: [0x56423e05dc57] asterisk astobj2.c:516 __ao2_ref()
# 2: [0x56423e1effde] asterisk cdr.c:2337 handle_channel_snapshot_update_message()
# 3: [0x56423e1a99b6] asterisk stasis_message_router.c:202 router_dispatch()
# 4: [0x56423e195f57] asterisk stasis.c:1266 dispatch_exec_async()
# 5: [0x56423e1bf6f6] asterisk taskprocessor.c:370 tps_task_free()
# 6: [inlined] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
# 7: [inlined] asterisk taskprocessor.c:209 default_tps_processing_function()
# 8: [0x56423e1d136f] asterisk utils.c:1301 dummy_start()
# 9: [0x7f29512db6db] libpthread.so.0 pthread_create.c:463 start_thread()
#10: [0x7f29504cca3f] libc.so.6 clone.S:97 clone()

[Jul 16 09:56:33] ERROR[26751] cdr.c: FRACK!, Failed assertion user_data is NULL (0)
[Jul 16 09:56:33] ERROR[26751] : Got 12 backtrace records
# 0: [0x56423e1d5ef3] asterisk utils.c:2454 __ast_assert_failed()
# 1: [0x56423e05d2e4] asterisk astobj2.c:212 log_bad_ao2()
# 2: [0x56423e060eba] asterisk astobj2_container.c:178 __ao2_unlink()
# 3: [0x56423e1f0004] asterisk cdr.c:2341 handle_channel_snapshot_update_message()
# 4: [0x56423e1a99b6] asterisk stasis_message_router.c:202 router_dispatch()
# 5: [0x56423e195f57] asterisk stasis.c:1266 dispatch_exec_async()
# 6: [0x56423e1bf6f6] asterisk taskprocessor.c:370 tps_task_free()
# 7: [inlined] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
# 8: [inlined] asterisk taskprocessor.c:209 default_tps_processing_function()
# 9: [0x56423e1d136f] asterisk utils.c:1301 dummy_start()
#10: [0x7f29512db6db] libpthread.so.0 pthread_create.c:463 start_thread()
#11: [0x7f29504cca3f] libc.so.6 clone.S:97 clone()

[Jul 16 09:56:33] DEBUG[26751] cdr.c: Finalized CDR for Snoop/SKTAOTP.jdote-00000006 - start 1626443793.404317 answer 1626443793.404317 end 1626443793.424157 dur 0.019 bill 0.019 dispo ANSWERED
[Jul 16 09:56:33] DEBUG[2528] res_rtp_asterisk.c: (0x7f287c03faf0) RTCP got report of 8 bytes from 192.168.10.69:59300

> cdr.c: FRACK!, Failed assertion user_data is NULL (0)
> -----------------------------------------------------
>
>                 Key: ASTERISK-29523
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-29523
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Applications/app_stasis, CDR/General
>    Affects Versions: 18.4.0
>            Reporter: BJ Weschke
>            Assignee: BJ Weschke
>
> In our daily pre-production regression, the following FRACK messages showed up in the log that seem to be related to a Snoop channel leaving a bridge. 
> Running core dump taken and will send under separate cover. 
> {noformat}
> [Jul 16 09:56:33] ERROR[26751] cdr.c: FRACK!, Failed assertion user_data is NULL (0)
> [Jul 16 09:56:33] DEBUG[3945][C-00000011] res_rtp_asterisk.c: (0x7f28a0187df0) RTCP got report of 100 bytes from 192.168.1.218:17095
> [Jul 16 09:56:33] DEBUG[2528] res_rtp_asterisk.c: (0x7f287c03faf0) RTCP got report of 56 bytes from 192.168.10.69:59300
> [Jul 16 09:56:33] ERROR[26751] : Got 11 backtrace records
> # 0: [0x56423e1d5ef3] asterisk utils.c:2454 __ast_assert_failed()
> # 1: [0x56423e05d6b6] asterisk astobj2.c:298 __ao2_unlock()
> # 2: [0x56423e1effd6] asterisk cdr.c:2336 handle_channel_snapshot_update_message()
> # 3: [0x56423e1a99b6] asterisk stasis_message_router.c:202 router_dispatch()
> # 4: [0x56423e195f57] asterisk stasis.c:1266 dispatch_exec_async()
> # 5: [0x56423e1bf6f6] asterisk taskprocessor.c:370 tps_task_free()
> # 6: [inlined] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
> # 7: [inlined] asterisk taskprocessor.c:209 default_tps_processing_function()
> # 8: [0x56423e1d136f] asterisk utils.c:1301 dummy_start()
> # 9: [0x7f29512db6db] libpthread.so.0 pthread_create.c:463 start_thread()
> #10: [0x7f29504cca3f] libc.so.6 clone.S:97 clone()
> [Jul 16 09:56:33] ERROR[26751] cdr.c: FRACK!, Failed assertion user_data is NULL (0)
> [Jul 16 09:56:33] ERROR[26751] : Got 12 backtrace records
> # 0: [0x56423e1d5ef3] asterisk utils.c:2454 __ast_assert_failed()
> # 1: [0x56423e05dc57] asterisk astobj2.c:516 __ao2_ref()
> # 2: [0x56423e1e99fb] asterisk cdr.c:981 cdr_all_unlink()
> # 3: [0x56423e1effde] asterisk cdr.c:2337 handle_channel_snapshot_update_message()
> # 4: [0x56423e1a99b6] asterisk stasis_message_router.c:202 router_dispatch()
> # 5: [0x56423e195f57] asterisk stasis.c:1266 dispatch_exec_async()
> # 6: [0x56423e1bf6f6] asterisk taskprocessor.c:370 tps_task_free()
> # 7: [inlined] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
> # 8: [inlined] asterisk taskprocessor.c:209 default_tps_processing_function()
> # 9: [0x56423e1d136f] asterisk utils.c:1301 dummy_start()
> #10: [0x7f29512db6db] libpthread.so.0 pthread_create.c:463 start_thread()
> #11: [0x7f29504cca3f] libc.so.6 clone.S:97 clone()
> [Jul 16 09:56:33] ERROR[26751] cdr.c: FRACK!, Failed assertion user_data is NULL (0)
> [Jul 16 09:56:33] DEBUG[3918] res_pjsip/pjsip_distributor.c: No dialog serializer for Response msg 200/MESSAGE/cseq=41591 (rdata0x7f28a00c43b8).  Using request transaction as basis.
> [Jul 16 09:56:33] DEBUG[3918] res_pjsip/pjsip_distributor.c: Found transaction tsx0x7f29381a0968 for Response msg 200/MESSAGE/cseq=41591 (rdata0x7f28a00c43b8).
> [Jul 16 09:56:33] DEBUG[3918] res_pjsip/pjsip_distributor.c: Found serializer pjsip/messaging on transaction tsx0x7f29381a0968
> [Jul 16 09:56:33] DEBUG[3918] res_pjsip.c: 0x7f28a00c0690: PJSIP tsx response received
> [Jul 16 09:56:33] DEBUG[3918] res_pjsip.c: 0x7f28a00c0690: Callbacks executed
> [Jul 16 09:56:33] DEBUG[3918] res_pjsip.c: 0x7f28a00c0690: wrapper destroyed
> [Jul 16 09:56:33] ERROR[26751] : Got 11 backtrace records
> # 0: [0x56423e1d5ef3] asterisk utils.c:2454 __ast_assert_failed()
> # 1: [0x56423e05dc57] asterisk astobj2.c:516 __ao2_ref()
> # 2: [0x56423e1effde] asterisk cdr.c:2337 handle_channel_snapshot_update_message()
> # 3: [0x56423e1a99b6] asterisk stasis_message_router.c:202 router_dispatch()
> # 4: [0x56423e195f57] asterisk stasis.c:1266 dispatch_exec_async()
> # 5: [0x56423e1bf6f6] asterisk taskprocessor.c:370 tps_task_free()
> # 6: [inlined] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
> # 7: [inlined] asterisk taskprocessor.c:209 default_tps_processing_function()
> # 8: [0x56423e1d136f] asterisk utils.c:1301 dummy_start()
> # 9: [0x7f29512db6db] libpthread.so.0 pthread_create.c:463 start_thread()
> #10: [0x7f29504cca3f] libc.so.6 clone.S:97 clone()
> [Jul 16 09:56:33] ERROR[26751] cdr.c: FRACK!, Failed assertion user_data is NULL (0)
> [Jul 16 09:56:33] ERROR[26751] : Got 12 backtrace records
> # 0: [0x56423e1d5ef3] asterisk utils.c:2454 __ast_assert_failed()
> # 1: [0x56423e05d2e4] asterisk astobj2.c:212 log_bad_ao2()
> # 2: [0x56423e060eba] asterisk astobj2_container.c:178 __ao2_unlink()
> # 3: [0x56423e1f0004] asterisk cdr.c:2341 handle_channel_snapshot_update_message()
> # 4: [0x56423e1a99b6] asterisk stasis_message_router.c:202 router_dispatch()
> # 5: [0x56423e195f57] asterisk stasis.c:1266 dispatch_exec_async()
> # 6: [0x56423e1bf6f6] asterisk taskprocessor.c:370 tps_task_free()
> # 7: [inlined] asterisk taskprocessor.c:1239 ast_taskprocessor_execute()
> # 8: [inlined] asterisk taskprocessor.c:209 default_tps_processing_function()
> # 9: [0x56423e1d136f] asterisk utils.c:1301 dummy_start()
> #10: [0x7f29512db6db] libpthread.so.0 pthread_create.c:463 start_thread()
> #11: [0x7f29504cca3f] libc.so.6 clone.S:97 clone()
> [Jul 16 09:56:33] DEBUG[26751] cdr.c: Finalized CDR for Snoop/SKTAOTP.jdote-00000006 - start 1626443793.404317 answer 1626443793.404317 end 1626443793.424157 dur 0.019 bill 0.019 dispo ANSWERED
> [Jul 16 09:56:33] DEBUG[2528] res_rtp_asterisk.c: (0x7f287c03faf0) RTCP got report of 8 bytes from 192.168.10.69:59300
> {noformat}

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