On Mon, Jun 14, 2021 at 1:16 PM Dan Cropp <d...@amtelco.com> wrote:
> I think you are onto something with the system time being slewed backwards.
>
> Logs showed this happened at the same time things went down
>
>
>
> systemd-timesyncd[684]: Synchronized to time server …..
>
We have a winner!!
>
>
>
>
> I’m looking at the coredump from my own box (same executable, just
> different box).
>
> Here is the output from the coredump you asked for.
>
>
>
> If it needs to be on the customer box, let me know. Pretty sure I can
> have someone with permissions access the box and do the same work I did.
>
As long as the binaries and distro are the same, examining a coredump on a
different box is fine. We do it all the time.
>
>
> (gdb) frame 6
>
> #6 0x00005588eef3a392 in hook_event_cb (chan=<optimized out>,
> frame=<optimized out>, event=<optimized out>, data=0x7f017411f4e0) at
> abstract_jb.c:1127
>
> 1127 abstract_jb.c: No such file or directory.
>
> (gdb) p now
>
> $1 = 18446744073709550143
>
Yeah that's -1473.
Could you open an ASTERISK issue for this? Something like "Negative time
differences causes an abort in fixedjitterbuffer.c".
We should just pass through any frame with a negative interval and remove
that ASSERT statement.
> (gdb) p now_tv
>
> $2 = <optimized out>
>
> (gdb) p *framedata
>
> $3 = {jb_impl = 0x5588ef40b3e0 <avail_impl>, jb_conf = {flags = 0,
> max_size = 200, resync_threshold = 1000, impl = "fixed\000\000\000䚗@",
> target_extra = 40}, start_tv = {tv_sec = 1623549920, tv_usec = 123464},
> last_format = 0x0,
>
> timer = 0x7f0174150fc0, timer_interval = 20, timer_fd = 379, first = 0,
> audio_stream_id = -1, audio_stream_sync = {timestamp = 0, ntp = {tv_sec =
> 0, tv_usec = 0}}, video_stream_id = -1, video_stream_sync = {timestamp = 0,
> ntp = {
>
> tv_sec = 0, tv_usec = 0}}, early_frames = {first = 0x0, last = 0x0},
> early_frame_count = 0, last_audio_ntp_timestamp = {tv_sec = 0, tv_usec =
> 0}, audio_flowing = 0, jb_obj = 0x7f01741b1990}
>
>
>
> Dan
>
>
>
> *From:* asterisk-dev <asterisk-dev-boun...@lists.digium.com> *On Behalf
> Of *George Joseph
> *Sent:* Monday, June 14, 2021 1:58 PM
> *To:* Asterisk Developers Mailing List <asterisk-dev@lists.digium.com>
> *Subject:* Re: [asterisk-dev] Asterisk crash
>
>
>
> That's pretty weird. The ASSERT in frame 4 makes sure that the time
> difference between the frame's timestamp and the current time is positive
> so a negative value will cause the assert. Actually, I think there's a
> bug there. Most asserts in Asterisk are enabled only when it's built with
> --enable-dev-mode. This assert seems to trigger even without
> --enable-dev-mode.
>
>
>
> Anyway, if you still have the actual coredump, it'd be interesting to do
> the following in gdb...
>
>
>
> gdb> frame 6
>
> gdb> p now
>
> gdb> p now_tv
>
> gdb> p *framedata
>
>
>
> I'm wondering if the system time is being slewed backwards by ntpd,
> chronyd, systemd-timesyncd, etc.
>
>
>
>
>
> On Mon, Jun 14, 2021 at 10:49 AM Dan Cropp <d...@amtelco.com> wrote:
>
> We have a customer with asterisk 16.17.0 installed. Every once in a
> while, we have been seeing a crash. We have upgraded the version a couple
> times, but this random crashing issue has been going on for some time.
>
>
>
> Over the weekend, it happened again. This time, I have a .crash file from
> it.
>
> Put it through apport-unpack and think I have a good CoreDump from it.
>
> Running asterisk 16.17.0 here is what the gdb backtrace is showing.
>
>
>
> Program terminated with signal SIGABRT, Aborted.
>
> #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
>
> 51 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
>
> [Current thread is 1 (Thread 0x7f014097d700 (LWP 20262))]
>
> (gdb) bt
>
> #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
>
> #1 0x00007f027877a921 in __GI_abort () at abort.c:79
>
> #2 0x00007f027876a48a in __assert_fail_base (fmt=0x7f02788f1750
> "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
> assertion=assertion@entry=0x5588ef1864a9
> "now >= 0",
>
> file=file@entry=0x5588ef18645a "fixedjitterbuf.c", line=line@entry=293,
> function=function@entry=0x5588ef1864f8 <__PRETTY_FUNCTION__.9166>
> "fixed_jb_get")
>
> at assert.c:92
>
> #3 0x00007f027876a502 in __GI___assert_fail
> (assertion=assertion@entry=0x5588ef1864a9
> "now >= 0", file=file@entry=0x5588ef18645a "fixedjitterbuf.c",
>
> line=line@entry=293, function=function@entry=0x5588ef1864f8
> <__PRETTY_FUNCTION__.9166> "fixed_jb_get") at assert.c:101
>
> #4 0x00005588eeffe999 in fixed_jb_get (jb=<optimized out>,
> frame=frame@entry=0x7f01409785c0, now=<optimized out>, interpl=<optimized
> out>) at fixedjitterbuf.c:293
>
> #5 0x00005588eef39ee2 in jb_get_fixed (jb=<optimized out>,
> fout=0x7f0140978628, now=<optimized out>, interpl=<optimized out>) at
> abstract_jb.c:675
>
> #6 0x00005588eef3a392 in hook_event_cb (chan=<optimized out>,
> frame=<optimized out>, event=<optimized out>, data=0x7f017411f4e0) at
> abstract_jb.c:1127
>
> #7 0x00005588ef008935 in framehook_list_push_event
> (framehooks=0x7f01741bca40, frame=frame@entry=0x5588ef416aa0
> <ast_null_frame>,
>
> event=event@entry=AST_FRAMEHOOK_EVENT_READ) at framehook.c:116
>
> #8 0x00005588ef009177 in ast_framehook_list_read_event
> (framehooks=<optimized out>, frame=frame@entry=0x5588ef416aa0
> <ast_null_frame>) at framehook.c:320
>
> #9 0x00005588eefbb1b1 in __ast_read (chan=chan@entry=0x7f016c1abf30,
> dropaudio=dropaudio@entry=0, dropnondefault=dropnondefault@entry=1) at
> channel.c:3779
>
> #10 0x00005588eefbd40c in ast_read (chan=chan@entry=0x7f016c1abf30) at
> channel.c:4285
>
> #11 0x00007f01cbf77b9c in async_agi_read_frame (chan=0x7f016c1abf30) at
> res_agi.c:1763
>
> #12 launch_asyncagi (efd=0x0, argv=0x7f0140978ae8, argc=<optimized out>,
> chan=0x7f016c1abf30) at res_agi.c:1960
>
> #13 launch_script (opid=<synthetic pointer>, efd=0x0, fds=0x7f0140978a30,
> argv=0x7f0140978ae8, argc=<optimized out>, script=<optimized out>,
> chan=0x7f016c1abf30)
>
> at res_agi.c:2213
>
> #14 agi_exec_full (chan=0x7f016c1abf30, data=<optimized out>,
> enhanced=<optimized out>, dead=0) at res_agi.c:4521
>
> #15 0x00005588ef04bf92 in pbx_exec (c=c@entry=0x7f016c1abf30,
> app=app@entry=0x5588efbed4b0, data=data@entry=0x7f014097ac00 "agi:async")
> at pbx_app.c:492
>
> #16 0x00005588ef03d062 in pbx_extension_helper (c=c@entry=0x7f016c1abf30,
> context=0x7f016c1ac8f0 "IS", exten=exten@entry=0x7f016c1ac940 "1234",
>
> priority=priority@entry=15, label=label@entry=0x0,
> callerid=callerid@entry=0x0, action=E_SPAWN, found=0x7f014097ccac,
> combined_find_spawn=1, con=0x0) at pbx.c:2947
>
> #17 0x00005588ef041143 in ast_spawn_extension (combined_find_spawn=1,
> found=0x7f014097ccac, callerid=0x0, priority=15, exten=0x7f016c1ac940
> "1234",
>
> context=<optimized out>, c=0x7f016c1abf30) at pbx.c:4206
>
> #18 __ast_pbx_run (c=c@entry=0x7f016c1abf30, args=args@entry=0x0) at
> pbx.c:4380
>
> #19 0x00005588ef04282b in pbx_thread (data=data@entry=0x7f016c1abf30) at
> pbx.c:4704
>
> #20 0x00005588ef0cf41f in dummy_start (data=<optimized out>) at
> utils.c:1299
>
> #21 0x00007f02793216db in start_thread (arg=0x7f014097d700) at
> pthread_create.c:463
>
> #22 0x00007f027885b71f in clone () at
> ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
>
>
>
>
>
> Any suggestions of what I could try?
>
>
>
> Dan
>
> --
> _____________________________________________________________________
> -- Bandwidth and Colocation Provided by http://www.api-digital.com --
>
> asterisk-dev mailing list
> To UNSUBSCRIBE or update options visit:
> http://lists.digium.com/mailman/listinfo/asterisk-dev
>
> --
> _____________________________________________________________________
> -- Bandwidth and Colocation Provided by http://www.api-digital.com --
>
> asterisk-dev mailing list
> To UNSUBSCRIBE or update options visit:
> http://lists.digium.com/mailman/listinfo/asterisk-dev
--
_____________________________________________________________________
-- Bandwidth and Colocation Provided by http://www.api-digital.com --
asterisk-dev mailing list
To UNSUBSCRIBE or update options visit:
http://lists.digium.com/mailman/listinfo/asterisk-dev
