firebird-support - Re: DROP table statement hangs Firebird Server process with 100% CPU usage

Subject	Re: DROP table statement hangs Firebird Server process with 100% CPU usage
Author
Post date	2018-06-16T20:06:17Z

Thanks. I just realized that the database was created with 2.5.8, and the bug occurs with 2.5.6 on that database.

However, the bug did not occur with a previous version of my database on 2.5.8, granted that file was much smaller compared to what it has grown to be.

Upgrading (manually) from 2.5.6 to 2.5.8, the bug occurs. The following is done while the process is running in its endless loop:

/opt/firebird/bin/.debug/: Success.

Attaching to process 20396

[New LWP 20401]

[New LWP 20402]

[New LWP 20952]

[New LWP 20961]

[New LWP 20962]

[New LWP 20963]

[New LWP 20964]

[Thread debugging using libthread_db enabled]

Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".

0x00007f4090f4374d in poll () at ../sysdeps/unix/syscall-template.S:84

84 ../sysdeps/unix/syscall-template.S: No such file or directory.

(gdb) bt

#0 0x00007f4090f4374d in poll () at ../sysdeps/unix/syscall-template.S:84

#1 0x00000000006d98e5 in Select::select (timeout=<optimized out>, this=<optimized out>) at ../src/remote/inet.cpp:381

#2 select_wait (selct=<optimized out>, main_port=<optimized out>) at ../src/remote/inet.cpp:2461

#3 select_multi (main_port=0x7f4090c16bd0, buffer=0x7f408fabb000 "", bufsize=8192, length=0x7fffc77b11ce, port=...) at ../src/remote/inet.cpp:2236

#4 0x00000000004152d0 in SRVR_multi_thread (main_port=0x7f4090c16bd0, flags=<optimized out>) at ../src/remote/server.cpp:636

#5 0x000000000040d72c in server_main (argc=<optimized out>, argv=<optimized out>) at ../src/remote/inet_server.cpp:430

#6 0x00007f4090e68830 in __libc_start_main (main=0x4198c0 <main(int, char**)>, argc=1, argv=0x7fffc77b2838, init=<optimized out>, fini=<optimized out>,

rtld_fini=<optimized out>, stack_end=0x7fffc77b2828) at ../csu/libc-start.c:291

#7 0x000000000040cef9 in _start ()

(gdb) thread apply all bt

Thread 8 (Thread 0x7f4087fff700 (LWP 20964)):

#0 __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135

#1 0x00007f409121be42 in __GI___pthread_mutex_lock (mutex=0x7f408f8aa830) at ../nptl/pthread_mutex_lock.c:115

#2 0x000000000060c1b4 in Firebird::Mutex::enter (this=<optimized out>) at ../src/include/../common/classes/locks.h:170

#3 Jrd::Database::Sync::lock (ast=<optimized out>, this=<optimized out>) at ../src/jrd/../jrd/../jrd/Database.h:163

#4 Jrd::Database::Checkout::~Checkout (this=<optimized out>, __in_chrg=<optimized out>) at ../src/jrd/../jrd/../jrd/Database.h:301

#5 garbage_collector (arg=<optimized out>) at ../src/jrd/vio.cpp:4361

#6 0x000000000042ae92 in (anonymous namespace)::ThreadArgs::run (this=<optimized out>) at ../src/jrd/ThreadStart.cpp:128

#7 (anonymous namespace)::threadStart (arg=0x7f408f8aaf90) at ../src/jrd/ThreadStart.cpp:139

#8 0x00007f40912196ba in start_thread (arg=0x7f4087fff700) at pthread_create.c:333

#9 0x00007f4090f4f41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 7 (Thread 0x7f408dcf5700 (LWP 20963)):

#0 __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135

#1 0x00007f409121be42 in __GI___pthread_mutex_lock (mutex=0x7f408f8aa830) at ../nptl/pthread_mutex_lock.c:115

#2 0x00000000004f1768 in Firebird::Mutex::enter (this=<optimized out>) at ../src/include/../common/classes/locks.h:170

#3 Jrd::Database::Sync::lock (ast=<optimized out>, this=<optimized out>) at ../src/jrd/../jrd/../jrd/Database.h:163

#4 Jrd::Database::Checkout::~Checkout (this=<optimized out>, __in_chrg=<optimized out>) at ../src/jrd/../jrd/../jrd/Database.h:301

#5 cache_writer (arg=<optimized out>) at ../src/jrd/cch.cpp:4274

#6 0x000000000042ae92 in (anonymous namespace)::ThreadArgs::run (this=<optimized out>) at ../src/jrd/ThreadStart.cpp:128

#7 (anonymous namespace)::threadStart (arg=0x7f408f8aaf90) at ../src/jrd/ThreadStart.cpp:139

#8 0x00007f40912196ba in start_thread (arg=0x7f408dcf5700) at pthread_create.c:333

#9 0x00007f4090f4f41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 6 (Thread 0x7f40877fe700 (LWP 20962)):

#0 0x00007f4091221a15 in futex_abstimed_wait_cancelable (private=0, abstime=0x7f40877fdb40, expected=0, futex_word=0x7f408ed62268)

at ../sysdeps/unix/sysv/linux/futex-internal.h:205

#1 do_futex_wait (sem=sem@entry=0x7f408ed62268, abstime=abstime@entry=0x7f40877fdb40) at sem_waitcommon.c:111

#2 0x00007f4091221adf in __new_sem_wait_slow (sem=0x7f408ed62268, abstime=0x7f40877fdb40) at sem_waitcommon.c:181

#3 0x00007f4091221b92 in sem_timedwait (sem=<optimized out>, abstime=<optimized out>) at sem_timedwait.c:36

#4 0x000000000073bb20 in Firebird::SignalSafeSemaphore::tryEnter (this=0x7f408ed62268, seconds=<optimized out>, milliseconds=<optimized out>)

at ../src/common/classes/semaphore.cpp:171

#5 0x000000000060c199 in garbage_collector (arg=<optimized out>) at ../src/jrd/vio.cpp:4361

#6 0x000000000042ae92 in (anonymous namespace)::ThreadArgs::run (this=<optimized out>) at ../src/jrd/ThreadStart.cpp:128

#7 (anonymous namespace)::threadStart (arg=0x7f408fab4ae0) at ../src/jrd/ThreadStart.cpp:139

#8 0x00007f40912196ba in start_thread (arg=0x7f40877fe700) at pthread_create.c:333

#9 0x00007f4090f4f41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 5 (Thread 0x7f408cce3700 (LWP 20961)):

#0 0x00007f4091221a15 in futex_abstimed_wait_cancelable (private=0, abstime=0x7f408cce2bf0, expected=0, futex_word=0x7f408ed62208)

at ../sysdeps/unix/sysv/linux/futex-internal.h:205

#1 do_futex_wait (sem=sem@entry=0x7f408ed62208, abstime=abstime@entry=0x7f408cce2bf0) at sem_waitcommon.c:111

#2 0x00007f4091221adf in __new_sem_wait_slow (sem=0x7f408ed62208, abstime=0x7f408cce2bf0) at sem_waitcommon.c:181

---Type <return> to continue, or q <return> to quit---

#3 0x00007f4091221b92 in sem_timedwait (sem=<optimized out>, abstime=<optimized out>) at sem_timedwait.c:36

#4 0x000000000073bb20 in Firebird::SignalSafeSemaphore::tryEnter (this=0x7f408ed62208, seconds=<optimized out>, milliseconds=<optimized out>)

at ../src/common/classes/semaphore.cpp:171

#5 0x00000000004f174b in cache_writer (arg=<optimized out>) at ../src/jrd/cch.cpp:4274

#6 0x000000000042ae92 in (anonymous namespace)::ThreadArgs::run (this=<optimized out>) at ../src/jrd/ThreadStart.cpp:128

#7 (anonymous namespace)::threadStart (arg=0x7f408fab4ae0) at ../src/jrd/ThreadStart.cpp:139

#8 0x00007f40912196ba in start_thread (arg=0x7f408cce3700) at pthread_create.c:333

#9 0x00007f4090f4f41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 4 (Thread 0x7f408e556700 (LWP 20952)):

#0 Jrd::RuntimeStatistics::bumpValue (index=<optimized out>, this=<optimized out>) at ../src/jrd/../jrd/../jrd/RuntimeStatistics.h:148

#1 Jrd::thread_db::bumpStats (index=<optimized out>, this=<optimized out>) at ../src/jrd/../jrd/jrd.h:762

#2 get_buffer (tdbb=0x7f408e5550f0, page=..., latch=Jrd::LATCH_exclusive, latch_wait=<optimized out>) at ../src/jrd/cch.cpp:4994

#3 0x00000000004f3f92 in CCH_fetch_lock (tdbb=0x7f408e5550f0, window=0x7f408e554830, lock_type=6, wait=1, page_type=2 '\002') at ../src/jrd/cch.cpp:889

#4 0x00000000004f446c in CCH_FETCH_LOCK (page_type=<optimized out>, wait=<optimized out>, lock_type=<optimized out>, window=<optimized out>, tdbb=<optimized out>)

at ../src/jrd/../jrd/cch_proto.h:91

#5 CCH_fetch (tdbb=0x7f408e5550f0, window=0x7f408e554830, lock_type=20720, page_type=2 '\002', checksum=1, latch_wait=0, read_shadow=true) at ../src/jrd/cch.cpp:779

#6 0x00000000005a6d0b in CCH_FETCH (page_type=<optimized out>, lock_type=<optimized out>, window=<optimized out>, tdbb=<optimized out>) at ../src/jrd/../jrd/cch_proto.h:71

#7 PAG_release_page (tdbb=0x7f408e5550f0, number=..., prior_page=...) at ../src/jrd/pag.cpp:1813

#8 0x000000000044bbac in delete_tail (length=<optimized out>, page_space=<optimized out>, header=<optimized out>, tdbb=<optimized out>)

at ../temp/superserver/jrd/dpm.cpp:2514

#9 DPM_delete_relation_pages (tdbb=0x7f408e5550f0, relation=0x7f408ebca7d8, relPages=0x7f408ebca988) at ../temp/superserver/jrd/dpm.cpp:1043

#10 0x000000000044be4b in DPM_delete_relation (tdbb=0x7f408e5550f0, relation=0x7f408ebca7d8) at ../temp/superserver/jrd/dpm.cpp:969

#11 0x0000000000518491 in delete_relation (tdbb=0x7f408e5550f0, phase=<optimized out>, work=0x7f408ea82100, transaction=0x7f408eb6b7c0)

at ../temp/superserver/jrd/dfw.cpp:5179

#12 0x000000000050c5e9 in DFW_perform_work (tdbb=0x7f408e5550f0, transaction=0x7f408eb6b7c0) at ../temp/superserver/jrd/dfw.cpp:1197

#13 0x00000000005f3d6b in TRA_commit (tdbb=0x7f408e5550f0, transaction=0x7f408eb6b7c0, retaining_flag=false) at ../src/jrd/tra.cpp:496

#14 0x0000000000569b3d in commit (tdbb=0x7f408e5550f0, transaction=<optimized out>, retaining_flag=240) at ../src/jrd/jrd.cpp:4615

#15 0x0000000000569bd6 in JRD_commit_transaction (tdbb=0x7f408e5550f0, transaction=0x7f408f8ab170) at ../src/jrd/jrd.cpp:7057

#16 0x0000000000571c21 in jrd8_commit_transaction (user_status=0x7f408e5559a0, tra_handle=0x7f408f8ab170) at ../src/jrd/jrd.cpp:1811

#17 0x0000000000436cdb in isc_commit_transaction (user_status=<optimized out>, tra_handle=0x7f4090c0f4a8) at ../src/jrd/why.cpp:1749

#18 0x0000000000410487 in rem_port::end_transaction (this=0x7f408fab1800, operation=op_commit, release=<optimized out>, sendL=0x7f408faaff88)

at ../src/remote/server.cpp:2086

#19 0x00000000004173e4 in process_packet (port=0x7f408fab1800, sendL=0x7f408faaff88, receive=0x7f408fab0398, result=0x7f408e555ea8) at ../src/remote/server.cpp:3441

#20 0x00000000004183a7 in loopThread () at ../src/remote/server.cpp:5268

#21 0x000000000042ae92 in (anonymous namespace)::ThreadArgs::run (this=<optimized out>) at ../src/jrd/ThreadStart.cpp:128

#22 (anonymous namespace)::threadStart (arg=0x7f4090c0f770) at ../src/jrd/ThreadStart.cpp:139

#23 0x00007f40912196ba in start_thread (arg=0x7f408e556700) at pthread_create.c:333

#24 0x00007f4090f4f41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 3 (Thread 0x7f408f8a9700 (LWP 20402)):

#0 0x00007f4091221a15 in futex_abstimed_wait_cancelable (private=0, abstime=0x7f408f8a8e60, expected=0, futex_word=0x7f408f8ab038)

at ../sysdeps/unix/sysv/linux/futex-internal.h:205

#1 do_futex_wait (sem=sem@entry=0x7f408f8ab038, abstime=abstime@entry=0x7f408f8a8e60) at sem_waitcommon.c:111

---Type <return> to continue, or q <return> to quit---

#2 0x00007f4091221adf in __new_sem_wait_slow (sem=0x7f408f8ab038, abstime=0x7f408f8a8e60) at sem_waitcommon.c:181

#3 0x00007f4091221b92 in sem_timedwait (sem=<optimized out>, abstime=<optimized out>) at sem_timedwait.c:36

#4 0x000000000073bb20 in Firebird::SignalSafeSemaphore::tryEnter (this=0x7f408f8ab038, seconds=<optimized out>, milliseconds=<optimized out>)

at ../src/common/classes/semaphore.cpp:171

#5 0x0000000000635dd1 in Jrd::ConfigStorage::touchThreadFunc (this=0x7f4090c11250) at ../src/jrd/trace/TraceConfigStorage.cpp:352

#6 0x0000000000635ed9 in Jrd::ConfigStorage::touchThread (arg=0x7f408f8ab038) at ../src/jrd/trace/TraceConfigStorage.cpp:338

#7 0x000000000042ae92 in (anonymous namespace)::ThreadArgs::run (this=<optimized out>) at ../src/jrd/ThreadStart.cpp:128

#8 (anonymous namespace)::threadStart (arg=0x7f408f8ba110) at ../src/jrd/ThreadStart.cpp:139

#9 0x00007f40912196ba in start_thread (arg=0x7f408f8a9700) at pthread_create.c:333

#10 0x00007f4090f4f41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 2 (Thread 0x7f40903ce700 (LWP 20401)):

#0 0x00007f4091221827 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0, futex_word=0x7f4090c1b9f8) at ../sysdeps/unix/sysv/linux/futex-internal.h:205

#1 do_futex_wait (sem=sem@entry=0x7f4090c1b9f8, abstime=0x0) at sem_waitcommon.c:111

#2 0x00007f40912218d4 in __new_sem_wait_slow (sem=0x7f4090c1b9f8, abstime=0x0) at sem_waitcommon.c:181

#3 0x00007f409122197a in __new_sem_wait (sem=<optimized out>) at sem_wait.c:29

#4 0x000000000073b9f8 in Firebird::SignalSafeSemaphore::enter (this=<optimized out>) at ../src/common/classes/semaphore.cpp:132

#5 0x000000000043cb59 in (anonymous namespace)::shutdownThread () at ../src/jrd/why.cpp:933

#6 0x000000000042ae92 in (anonymous namespace)::ThreadArgs::run (this=<optimized out>) at ../src/jrd/ThreadStart.cpp:128

#7 (anonymous namespace)::threadStart (arg=0x7f4090c129c0) at ../src/jrd/ThreadStart.cpp:139

#8 0x00007f40912196ba in start_thread (arg=0x7f40903ce700) at pthread_create.c:333

#9 0x00007f4090f4f41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Thread 1 (Thread 0x7f4092731740 (LWP 20396)):