[Cin] Ctimebar.C
Good Guy
good1.2guy at gmail.com
Tue Mar 3 00:40:32 CET 2020
Hi,
preview_start=0, preview_end=-1 means that preview is not active
this is the result from the constructor: localsession.C:92
There is no difference at the event layer between single and
double clicks. The ButtonPress/ButtonRelease events have
timestamps, and if the button nums matches and it is "really" quick
(300 ms, per bcresources.C:841) then it is a double click.
If you are seeing a deadlock type hang, (a race between locks)
the best way I know to try to identify the culprits is to:
1) start cin in gdb
2) run the session which hangs until it hangs.
3) hit ^C, which will be intercepted by gdb.
4) enter: "p dump()"
This will produce a lock trace table dump.
You can do this at any time.
On an idle system it looks like this:
(gdb) p dump()
signal_entry: lock table size=22
0x5b098b0 VIconThread::draw_lock, VIconThread::run 0 0x7fffe0ab2700
0x6117a10 CWindowTool::input_lock, CWindowTool::run 0x7fffdb7fe700
0x625f340 PlaybackEngine::output_lock, PlaybackEngine::run
0x7fffdaffd700
0x6265ce0 BC_DialogThread::active_lock, BC_DialogThread::run
0x7fffda7fc700 *
0x7fffd41c4dc0 PlaybackEngine::output_lock, PlaybackEngine::run
0x7fffd97fa700
0x66924d0 RecordSetChannel::change_channel, (null) 0x7fffcbfff700
0x6698880 RecordCutAdsStatus::wait_lock, RecordCutAdsStatus::run
0x7fffcb7fe700
0x67a52a0 ChannelInfo::scan_lock, (null) 0x7fffcaffd700
0x67a68d0 SWindow::swin_lock, (null) 0x7fffca7fc700
0x69dafb0 MainIndexes::input_lock, MainIndexes::run 1 0x7fffc8ff9700
0x648a2d0 ResourceThread::draw_lock, ResourceThread::run 0x7fffd2ffd700
0x4926280 BC_Synchronous::next_command, BC_Synchronous::run
0x7fffb2ffd700
0x4923590 MWindow::run_lock, MWindow::run 0x7ffff6d43840 *
0x7fffd40028c0 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffda7fc700
lock_items: 20
lock_frees: 3
$1 = void
The columns are lock_addr, lock_name, lock_loc, thread_id
The locks with the * on the end are waiting (maybe hung).
== To see what that thread is doing, use: "thr find <thread_id>" like this:
(gdb) thr find 0x7ffff6d43840
Thread 1 has target id 'Thread 0x7ffff6d43840 (LWP 184411)'
== Then switch to that thread like this:
(gdb) thr 1
[Switching to thread 1 (Thread 0x7ffff6d43840 (LWP 184411))]
#0 0x00007ffff7cafd45 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
== Then get a backtrace to see what is on the stack.
(gdb) thr 1
(gdb) bt
#0 0x00007ffff7cafd45 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
#1 0x0000000000d9679a in Condition::lock (this=0x6267920,
location=0x2bc1b07 "BC_WindowBase::get_event") at condition.C:64
#2 0x0000000000d8e61b in BC_WindowBase::get_event (this=0x6265f50) at
bcwindowbase.C:4557
#3 0x0000000000d839f1 in BC_WindowBase::dispatch_event (this=0x6265f50) at
bcwindowbase.C:917
#4 0x0000000000d82ff3 in BC_WindowBase::run_window (this=0x6265f50) at
bcwindowbase.C:741
#5 0x0000000000b9851f in MWindow::run (this=0x7fffffffbc80) at
mwindow.C:2898
#6 0x0000000000b50096 in main (argc=1, argv=0x7fffffffd798) at main.C:389
In this case, it is simply a lock used by the main program running mwindow,
to wait for it to finish before destroying a bunch of stuff. It stays
locked
while the program runs, until it is release by the mwindow so the destructor
can lock it, which prevents the destructor from running until mwindow is
done.
Not a hang.
A live session lock trace table is more complex, this one has a playback
active:
[Detaching after vfork from child process 184602]
^C
Thread 1 "ci" received signal SIGINT, Interrupt.
0x00007ffff7cafd45 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
Missing separate debuginfos, use: dnf debuginfo-install
alsa-plugins-pulseaudio-1.2.2-1.fc31.x86_64
(gdb) p dump()
signal_entry: lock table size=27
0x5b098b0 VIconThread::draw_lock, VIconThread::run 0 0x7fffe0ab2700
0x6117a10 CWindowTool::input_lock, CWindowTool::run 0x7fffdb7fe700
0x6265ce0 BC_DialogThread::active_lock, BC_DialogThread::run
0x7fffda7fc700 *
0x66924d0 RecordSetChannel::change_channel, (null) 0x7fffcbfff700
0x6698880 RecordCutAdsStatus::wait_lock, RecordCutAdsStatus::run
0x7fffcb7fe700
0x67a52a0 ChannelInfo::scan_lock, (null) 0x7fffcaffd700
0x67a68d0 SWindow::swin_lock, (null) 0x7fffca7fc700
0x4926280 BC_Synchronous::next_command, BC_Synchronous::run
0x7fffb2ffd700
0x4923590 MWindow::run_lock, MWindow::run 0x7ffff6d43840 *
0x7fffd41c4dc0 PlaybackEngine::output_lock, PlaybackEngine::run
0x7fffd97fa700
0x69dafb0 MainIndexes::input_lock, MainIndexes::run 1 0x7fffc8ff9700
0x625f340 PlaybackEngine::output_lock, PlaybackEngine::run
0x7fffdaffd700
0x67a7360 BC_Repeater::pause_lock, BC_Repeater::run 0x7fffc9ffb700
0x7fffdaffd700
0x648a2d0 ResourceThread::draw_lock, ResourceThread::run 0x7fffd2ffd700
0x7fff78005140 AudioDevice::arm_lock, AudioDevice::arm_buffer
0x7fff68ff9700
0x648a9f0 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffd1ffb700
0x5b78cd0 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffe1c9b700
0x5baae00 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffc37fe700
0x67b2560 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffc27fc700
0x69dfd10 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffb3fff700
0x6267920 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7ffff6d43840
0x7fffd40028c0 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffda7fc700
0x648a9f0 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffd1ffb700
lock_items: 22
lock_frees: 5
AudioALSA::write_buffer err -32(Broken pipe) at sample 163840
$2 = void
Here you see the PlaybackEngine, BC_Synchronous (opengl video), AudioDevice
(audio),
and a bunch of idle threads. Still a normal situation.
If you find a "bad" guy, it will usually be because the XDisplayLock
function is
waiting on a locked window, and that window lock is held by a thread that
wants
a lock that the current task owns. A waits on B, B waits on A. deadlock.
Here I used gdb to errantly set a lock on the composer canvas window
(gdb) p window->lock_window("bug test lock")
$4 = 0
(gdb) c
Continuing.
and then I tried playback, which hangs, and I interrupt, and see this:
(gdb) p dump()
signal_entry: lock table size=28
0x5b098b0 VIconThread::draw_lock, VIconThread::run 0 0x7fffe0ab2700
0x6117a10 CWindowTool::input_lock, CWindowTool::run 0x7fffdb7fe700
0x6265ce0 BC_DialogThread::active_lock, BC_DialogThread::run
0x7fffda7fc700 *
0x66924d0 RecordSetChannel::change_channel, (null) 0x7fffcbfff700
0x6698880 RecordCutAdsStatus::wait_lock, RecordCutAdsStatus::run
0x7fffcb7fe700
0x67a52a0 ChannelInfo::scan_lock, (null) 0x7fffcaffd700
0x67a68d0 SWindow::swin_lock, (null) 0x7fffca7fc700
0x4926280 BC_Synchronous::next_command, BC_Synchronous::run
0x7fffb2ffd700
0x4923590 MWindow::run_lock, MWindow::run 0x7ffff6d43840 *
0x7fffd41c4dc0 PlaybackEngine::output_lock, PlaybackEngine::run
0x7fffd97fa700
0x69dafb0 MainIndexes::input_lock, MainIndexes::run 1 0x7fffc8ff9700
0x67a7360 BC_Repeater::pause_lock, BC_Repeater::run 0x7fffc9ffb700
0x7fffdaffd700
0x5baae00 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffc37fe700
0x5f86cd8 Cinelerra: Compositor, BC_Repeater::run 0x7fffc17fa700
0x648a2d0 ResourceThread::draw_lock, ResourceThread::run 0x7fffd2ffd700
0x7fff78007be0 AudioDevice::play_lock, AudioDevice::run 1 0x7fff4ffff700
0x5f86cd8 Cinelerra: Compositor, VDeviceX11::open_output 0x7fffdaffd700
0x648a9f0 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffd1ffb700
0x67b2560 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffc27fc700
0x5b78cd0 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffe1c9b700
0x69dfd10 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffb3fff700
0x6267920 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7ffff6d43840
0x7fffd40028c0 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffda7fc700
0x648a9f0 BC_WindowBase::event_condition, BC_WindowBase::get_event
0x7fffd1ffb700
lock_items: 23
lock_frees: 5
$7 = void
Because I had a good idea where to look (drawing on the locked canvas)
I tried the VDeviceX11::open_output locked thread:
(gdb) thr find 0x7fffdaffd700
Thread 8 has target id 'Thread 0x7fffdaffd700 (LWP 184434)'
(gdb) thr 8
[Switching to thread 8 (Thread 0x7fffdaffd700 (LWP 184434))]
#0 0x00007ffff7cafd45 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
(gdb) bt
#0 0x00007ffff7cafd45 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
#1 0x00007ffff7e97045 in _XDisplayLockWait () from /lib64/libX11.so.6
#2 0x00007ffff7e974ed in _XLockDisplay () from /lib64/libX11.so.6
#3 0x00007ffff7e96ebb in XLockDisplay () from /lib64/libX11.so.6
#4 0x0000000000d8adf3 in BC_WindowBase::lock_window (this=0x5f86cd0,
location=0x2b9b520 "VDeviceX11::open_output") at bcwindowbase.C:3322
#5 0x0000000000d8ada5 in BC_WindowBase::lock_window (this=0x60fbee0,
location=0x2b9b520 "VDeviceX11::open_output") at bcwindowbase.C:3313
#6 0x0000000000a2c470 in Canvas::lock_canvas (this=0x60fbe00,
loc=0x2b9b520 "VDeviceX11::open_output") at canvas.C:94
#7 0x0000000000ca2d55 in VDeviceX11::open_output (this=0x7fff78023110) at
vdevicex11.C:103
#8 0x0000000000ca6c59 in VideoDevice::open_output (this=0x7fff7800da10,
config=0x7fff78033bb0, rate=29.9700298, out_w=352, out_h=240,
output=0x60fbe00, single_frame=0) at videodevice.C:689
#9 0x0000000000c244d6 in RenderEngine::open_output (this=0x7fff7800a2d0)
at renderengine.C:328
#10 0x0000000000c23e7c in RenderEngine::arm_command (this=0x7fff7800a2d0,
command=0x5bb7f20) at renderengine.C:180
#11 0x0000000000bc1db3 in PlaybackEngine::arm_render_engine
(this=0x4a47220) at playbackengine.C:147
#12 0x0000000000bc282d in PlaybackEngine::run (this=0x4a47220) at
playbackengine.C:412
#13 0x0000000000da57bd in Thread::entrypoint (parameters=0x4a47220) at
thread.C:65
#14 0x00007ffff7ca94e2 in start_thread () from /lib64/libpthread.so.0
#15 0x00007ffff75336d3 in clone () from /lib64/libc.so.6
You can see it is waiting on the XDisplayLock, probably because the
composer is
hosed and has it. You can see the XDisplayLock owner (possible bad guy)
like this:
(gdb) up
#1 0x00007ffff7e97045 in _XDisplayLockWait () from /lib64/libX11.so.6
(gdb)
#2 0x00007ffff7e974ed in _XLockDisplay () from /lib64/libX11.so.6
(gdb)
#3 0x00007ffff7e96ebb in XLockDisplay () from /lib64/libX11.so.6
(gdb)
#4 0x0000000000d8adf3 in BC_WindowBase::lock_window (this=0x5f86cd0,
location=0x2b9b520 "VDeviceX11::open_output") at bcwindowbase.C:3322
3322 XLockDisplay(top_level->display);
(gdb) p /x top_level->display_lock_owner
$8 = 0x7fff6b7fe700
(gdb) thr find 0x7fff6b7fe700
Thread 83 has target id 'Thread 0x7fff6b7fe700 (LWP 184684)'
(gdb) bt
#0 0x00007ffff7cafd45 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
#1 0x00007ffff7e97045 in _XDisplayLockWait () from /lib64/libX11.so.6
#2 0x00007ffff7e974ed in _XLockDisplay () from /lib64/libX11.so.6
#3 0x00007ffff7e96ebb in XLockDisplay () from /lib64/libX11.so.6
#4 0x0000000000d8adf3 in BC_WindowBase::lock_window (this=0x5f86cd0,
location=0x2b9b520 "VDeviceX11::open_output") at bcwindowbase.C:3322
#5 0x0000000000d8ada5 in BC_WindowBase::lock_window (this=0x60fbee0,
location=0x2b9b520 "VDeviceX11::open_output") at bcwindowbase.C:3313
#6 0x0000000000a2c470 in Canvas::lock_canvas (this=0x60fbe00,
loc=0x2b9b520 "VDeviceX11::open_output") at canvas.C:94
#7 0x0000000000ca2d55 in VDeviceX11::open_output (this=0x7fff78023110) at
vdevicex11.C:103
#8 0x0000000000ca6c59 in VideoDevice::open_output (this=0x7fff7800da10,
config=0x7fff78033bb0, rate=29.9700298, out_w=352, out_h=240,
output=0x60fbe00, single_frame=0) at videodevice.C:689
#9 0x0000000000c244d6 in RenderEngine::open_output (this=0x7fff7800a2d0)
at renderengine.C:328
#10 0x0000000000c23e7c in RenderEngine::arm_command (this=0x7fff7800a2d0,
command=0x5bb7f20) at renderengine.C:180
#11 0x0000000000bc1db3 in PlaybackEngine::arm_render_engine
(this=0x4a47220) at playbackengine.C:147
#12 0x0000000000bc282d in PlaybackEngine::run (this=0x4a47220) at
playbackengine.C:412
#13 0x0000000000da57bd in Thread::entrypoint (parameters=0x4a47220) at
thread.C:65
#14 0x00007ffff7ca94e2 in start_thread () from /lib64/libpthread.so.0
#15 0x00007ffff75336d3 in clone () from /lib64/libc.so.6
this can be a good way to narrow down the locks and threads that are in play
during a deadlock. It is a good idea to very carefully record what you are
typing and/or mousing (the xevent stream drives all of this).
There is no magic bullet to fix a deadlock that I know.
If you can get some p dump()'s maybe I can help narrow it down, or
maybe the problem will be more obvious.
gg
On Mon, Mar 2, 2020 at 11:43 AM Andrew Randrianasulu <
randrianasulu at gmail.com> wrote:
> Hi, all
>
> So, I tried to debug non-working/freezing timebar in Compositor ....
>
> BC_WindowBase::dispatch_event 956 Cinelerra: Составитель 0xe277658 6
> (MotionNotify)
> BC_WindowBase::dispatch_event this=0xe3d9b40 1360
> BC_WindowBase::dispatch_event 956 Cinelerra: Составитель 0xdae2758 4
> (ButtonPress)
> CTimeBar:pixel_to_Position
> CTimeBar: pixel, 110
> CTimebar:pix_to_pos: Got EDL!
> CTimebar:pix_to_pos: prev_start 0.000000, prev_end -1.000000
> CTimeBar:pixel_to_pos start, 0, end 0
> BC_WindowBase::dispatch_event this=0xe2d10450 1360
> BC_WindowBase::dispatch_event this=0xe849748 1360
> BC_WindowBase::dispatch_event this=0xe582418 1360
> BC_WindowBase::dispatch_event this=0xe1480d0 1360
> BC_WindowBase::dispatch_event this=0xe920510 1360
> BC_WindowBase::dispatch_event this=0xe582418 1360
>
> additional printfs added by me:
>
> diff --git a/cinelerra-5.1/cinelerra/ctimebar.C
> b/cinelerra-5.1/cinelerra/ctimebar.C
> index b9fb0bd..e0a1ee5 100644
> --- a/cinelerra-5.1/cinelerra/ctimebar.C
> +++ b/cinelerra-5.1/cinelerra/ctimebar.C
> @@ -59,23 +59,30 @@ EDL* CTimeBar::get_edl()
>
> void CTimeBar::draw_time()
> {
> + printf("CTimeBar::draw_time before draw_range");
> draw_range();
> + printf("CTimeBar::draw_time after draw_range");
> }
>
>
> double CTimeBar::pixel_to_position(int pixel)
> {
> + printf("CTimeBar:pixel_to_Position \n");
> + printf("CTimeBar: pixel, %i \n", pixel);
> double start = 0, end = get_edl_length();
> EDL *edl = get_edl();
> if( edl ) {
> + printf("CTimebar:pix_to_pos: Got EDL!\n");
> double preview_start = edl->local_session->preview_start;
> double preview_end = edl->local_session->preview_end;
> + printf("CTimebar:pix_to_pos: prev_start %f, prev_end %f
> \n", preview_start, preview_end);
> if( preview_end >= 0 || preview_start > 0 )
> start = preview_start;
> if( preview_end >= 0 && preview_end < end )
> end = preview_end;
> }
> if( start > end ) start = end;
> + printf("CTimeBar:pixel_to_pos start, %d, end %d \n" , start, end);
> return start + (double)pixel * (end - start) / get_w();
> }
>
>
> Hm, so preview end for some reason become negative???
> --
> Cin mailing list
> Cin at lists.cinelerra-gg.org
> https://lists.cinelerra-gg.org/mailman/listinfo/cin
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.cinelerra-gg.org/pipermail/cin/attachments/20200302/d784dcdf/attachment-0001.html>
More information about the Cin
mailing list