Logging hangs in 2987+

[mvives]

Hi all,
We are trying to upgrade our application from CEF 2705 to something more recent and after a couple of days of weird issues, I'm asking here for some help

I managed to get our application running with the latest 2924 build from http://opensource.spotify.com/cefbuilds ... 64.tar.bz2
However, if I go to a more recent one (I tested 2987, 3029 & 3071), our exactly identical application is hanging at the first time CEF is trying to log something. Depending on the log level the lock is more or less soon, but it always happen.

I haven't found any change related to the logging in CEF in those branches so I am asking here for help

Following is a stack of the "hanging". Note that we are using a separate subprocess and as far as I know he is hanging at the same point.

Code: Select all

1  futex_wait                                 futex-internal.h             61   0x7fffed532a4f
2  futex_wait_simple                          futex-internal.h             135  0x7fffed532a4f
3  __pthread_once_slow                        pthread_once.c               105  0x7fffed532a4f
4  localtime_r                                zygote_main_linux.cc         285  0x7fffafc9baf1
5  Init                                       logging.cc                   784  0x7fffb07499c8
6  InitLibcLocaltimeFunctions                 zygote_main_linux.cc         207  0x7fffafc9ba15
7  __pthread_once_slow                        pthread_once.c               116  0x7fffed532a99
8  localtime_r                                zygote_main_linux.cc         285  0x7fffafc9baf1
9  Init                                       logging.cc                   784  0x7fffb07499c8
10 cef_log                                    base_impl.cc                 387  0x7fffb06851f4
11 cef::logging::LogMessage::~LogMessage      cef_logging.cc               180  0x7fffb705a7e4
12 CefAdapter::CefWindowInfo::SetAsWindowless cef_linux.cpp                65   0x7fffb70597d7
13 ChromiumBaseProduct::prepareCreateBrowser  chromium_base_product.cpp    185  0x7fffb74624c8
14 ChromiumProduct::createBrowser             chromium_product.cpp         142  0x7fffb747d156
15 ChromiumBaseProduct::loadPage              chromium_base_product.cpp    230  0x7fffb7462d8c
16 ChromiumBaseProduct::playContent           chromium_base_product.cpp    127  0x7fffb7461d26
17 AbstractMediaProduct::play                 abstract_media_product.cpp   207  0x7ffff741e04c
18 MediaProductController::playCurrentItem    media_product_controller.cpp 1278 0x7fffc3423da0
19 MediaProductController::heartbeat          media_product_controller.cpp 318  0x7fffc341c7e3
20 EmbedPlayerWidget::heartbeat               embed_player_widget.cpp      1245 0x7fffc33ce106
21 EmbedPlayerWidget::qt_static_metacall      moc_embed_player_widget.cpp  85   0x7fffc3470e77
22 QMetaObject::activate                      qobject.cpp                  3563 0x7ffff037c0f1
23 QMetaObject::activate                      qobject.cpp                  3438 0x7ffff037b92c
24 QTimer::timeout                            moc_qtimer.cpp               189  0x7ffff04146ff
25 QTimer::timerEvent                         qtimer.cpp                   255  0x7ffff0387bb4
26 QObject::event                             qobject.cpp                  1122 0x7ffff03754bb
27 QApplicationPrivate::notify_helper         qapplication.cpp             3467 0x7ffff119b0d8
28 QApplication::notify                       qapplication.cpp             2888 0x7ffff11985d0
29 QCoreApplication::notifyInternal           qcoreapplication.cpp         878  0x7ffff03362c5
30 QCoreApplication::sendEvent                qcoreapplication.h           232  0x7ffff033a09d
31 QTimerInfoList::activateTimers             qtimerinfo_unix.cpp          643  0x7ffff03b3cc1
32 timerSourceDispatch                        qeventdispatcher_glib.cpp    185  0x7ffff03b51ac
33 g_main_dispatch                            gmain.c                      3154 0x7fffe950a197
34 g_main_context_dispatch                    gmain.c                      3769 0x7fffe950a197
35 g_main_context_iterate                     gmain.c                      3840 0x7fffe950a3f0
36 g_main_context_iteration                   gmain.c                      3901 0x7fffe950a49c
37 QEventDispatcherGlib::processEvents        qeventdispatcher_glib.cpp    426  0x7ffff03b5bc2
38 QPAEventDispatcherGlib::processEvents      qeventdispatcher_glib.cpp    123  0x7fffe250d65c
39 QEventLoop::processEvents                  qeventloop.cpp               136  0x7ffff0332d00
40 QEventLoop::exec                           qeventloop.cpp               212  0x7ffff033302f
41 QCoreApplication::exec                     qcoreapplication.cpp         1131 0x7ffff0336a22
42 QGuiApplication::exec                      qguiapplication.cpp          1332 0x7ffff091e514
43 QApplication::exec                         qapplication.cpp             2692 0x7ffff1197e43
44 bsp                                        bsp.cpp                      127  0x436a63       
45 main                                       main.cpp                     61   0x43be20       


I know there is not a lot of information here but I hope it's enough

Regards,
Manuel Vives

[magreenblatt]

Is CefAdapter::CefWindowInfo::SetAsWindowless called before or after CefInitialize?

[mvives]

Way After.

[magreenblatt]

What OS are you running on? Does the problem reproduce with the cefclient or cefsimple sample applications?

[mvives]

I'm on Ubuntu 16.04 and I use spotify builds. I did not notice any issue with cefsimple, I'll try with cefclient tomorrow.
In case it can help our application use OSR

[Czarek]

Does it make any difference if you call CefInitialize before or after QApplication::exec?
Are you writing to debug.log file using non-CEF functons?

[mvives]

Nothing else is writing in the logs (In fact something was but when I remove it, the issue kept being the same)

Here is the stack when the application is stuck and the log level is verbose:

Code: Select all

1  futex_wait                                 futex-internal.h              61   0x7fffed532a4f
2  futex_wait_simple                          futex-internal.h              135  0x7fffed532a4f
3  __pthread_once_slow                        pthread_once.c                105  0x7fffed532a4f
4  localtime_r                                zygote_main_linux.cc          285  0x7fffafc9baf1
5  Init                                       logging.cc                    784  0x7fffb07499c8
6  InitLibcLocaltimeFunctions                 zygote_main_linux.cc          207  0x7fffafc9ba15
7  __pthread_once_slow                        pthread_once.c                116  0x7fffed532a99
8  localtime_r                                zygote_main_linux.cc          285  0x7fffafc9baf1
9  Init                                       logging.cc                    784  0x7fffb07499c8
10 EnableActivityReportHistogram              histogram_base.cc             133  0x7fffb0760aa3
11 Run                                        content_main_runner.cc        780  0x7fffb05b830a
12 Initialize                                 context.cc                    384  0x7fffb05fb58b
13 CefInitialize                              context.cc                    222  0x7fffb05fb1ec
14 cef_initialize                             libcef_dll.cc                 222  0x7fffaedd8ac3
15 CefInitialize                              libcef_dll_wrapper.cc         218  0x7fffb706fba6
16 CefAdapter::CefApp::CefInitialize          cef_app.cpp                   155  0x7fffb703cfae
17 ChromiumKit::initCef                       chromium_kit.cpp              521  0x7fffb744b6d8
18 ChromiumKit::createProduct                 chromium_kit.cpp              397  0x7fffb744984d
19 MediaProductFactory::product               media_product_factory.cpp     85   0x7ffff74b82f4
20 MediaProductBrokerImpl::createProduct      media_product_broker_impl.cpp 100  0x7fffc341438e
21 MediaProductController::createMediaProduct media_product_controller.cpp  1372 0x7fffc3424c77
22 MediaProductController::createMediaProduct media_product_controller.cpp  1319 0x7fffc34243ee
23 MediaProductController::prebufferProduct   media_product_controller.cpp  976  0x7fffc34216c0
24 MediaProductController::prepareNextItem    media_product_controller.cpp  887  0x7fffc3420adb
25 MediaProductController::verifyNextItem     media_product_controller.cpp  965  0x7fffc34214dd
26 MediaProductController::heartbeat          media_product_controller.cpp  313  0x7fffc341c7a2
27 EmbedPlayerWidget::heartbeat               embed_player_widget.cpp       1245 0x7fffc33ce106
28 EmbedPlayerWidget::qt_static_metacall      moc_embed_player_widget.cpp   85   0x7fffc3470e77
29 QMetaObject::activate                      qobject.cpp                   3563 0x7ffff037c0f1
30 QMetaObject::activate                      qobject.cpp                   3438 0x7ffff037b92c
31 QTimer::timeout                            moc_qtimer.cpp                189  0x7ffff04146ff
32 QTimer::timerEvent                         qtimer.cpp                    255  0x7ffff0387bb4
33 QObject::event                             qobject.cpp                   1122 0x7ffff03754bb
34 QApplicationPrivate::notify_helper         qapplication.cpp              3467 0x7ffff119b0d8
35 QApplication::notify                       qapplication.cpp              2888 0x7ffff11985d0
36 QCoreApplication::notifyInternal           qcoreapplication.cpp          878  0x7ffff03362c5
37 QCoreApplication::sendEvent                qcoreapplication.h            232  0x7ffff033a09d
38 QTimerInfoList::activateTimers             qtimerinfo_unix.cpp           643  0x7ffff03b3cc1
39 timerSourceDispatch                        qeventdispatcher_glib.cpp     185  0x7ffff03b51ac
40 idleTimerSourceDispatch                    qeventdispatcher_glib.cpp     232  0x7ffff03b52a7
41 g_main_dispatch                            gmain.c                       3154 0x7fffe950a197
42 g_main_context_dispatch                    gmain.c                       3769 0x7fffe950a197
43 g_main_context_iterate                     gmain.c                       3840 0x7fffe950a3f0
44 g_main_context_iteration                   gmain.c                       3901 0x7fffe950a49c
45 QEventDispatcherGlib::processEvents        qeventdispatcher_glib.cpp     426  0x7ffff03b5bc2
46 QPAEventDispatcherGlib::processEvents      qeventdispatcher_glib.cpp     123  0x7fffe250d65c
47 QEventLoop::processEvents                  qeventloop.cpp                136  0x7ffff0332d00
48 QEventLoop::exec                           qeventloop.cpp                212  0x7ffff033302f
49 QCoreApplication::exec                     qcoreapplication.cpp          1131 0x7ffff0336a22
50 QGuiApplication::exec                      qguiapplication.cpp           1332 0x7ffff091e514
51 QApplication::exec                         qapplication.cpp              2692 0x7ffff1197e43
52 bsp                                        bsp.cpp                       127  0x436a63       
53 main                                       main.cpp                      61   0x43be20       



I'll try to test with CefInitialize called before QApplication::exec but due to the architecture of our application it will take me a bit of time
I'll also try cefclient with osr to see if I can repro

[mvives]

I'm not able to repro with cefsimple of cefclient.

I'll try to move the call to CefInitialize earlier in the loop

[Czarek]

Try also setting log level to LOG_FATAL and log file to an empty string.

[mvives]

I'm setting the log-severity through cef_log_severity_t, there is no fatal there