Logging hangs in 2987+

Having problems with building or using CEF's C/C++ APIs? This forum is here to help. Please do not post bug reports or feature requests here.

Re: Logging hangs in 2987+

Postby mvives » Fri May 05, 2017 12:03 pm

If I use CefInitialize before QApplication::exec, the behavior is the same.

Here is the stack:
Code: Select all
1  futex_wait                        futex-internal.h       61  0x7fffe605ca4f
2  futex_wait_simple                 futex-internal.h       135 0x7fffe605ca4f
3  __pthread_once_slow               pthread_once.c         105 0x7fffe605ca4f
4  localtime_r                       zygote_main_linux.cc   285 0x7fffe7c17af1
5  Init                              logging.cc             784 0x7fffe86c59c8
6  InitLibcLocaltimeFunctions        zygote_main_linux.cc   207 0x7fffe7c17a15
7  __pthread_once_slow               pthread_once.c         116 0x7fffe605ca99
8  localtime_r                       zygote_main_linux.cc   285 0x7fffe7c17af1
9  Init                              logging.cc             784 0x7fffe86c59c8
10 EnableActivityReportHistogram     histogram_base.cc      133 0x7fffe86dcaa3
11 Run                               content_main_runner.cc 780 0x7fffe853430a
12 Initialize                        context.cc             384 0x7fffe857758b
13 CefInitialize                     context.cc             222 0x7fffe85771ec
14 cef_initialize                    libcef_dll.cc          222 0x7fffe6d54ac3
15 CefInitialize                     libcef_dll_wrapper.cc  218 0x7ffff7a85ba6
16 CefAdapter::CefApp::CefInitialize cef_app.cpp            155 0x7ffff7a52fae
17 PlayerApp::PlayerApp              player_app.cpp         44  0x43fe89       
18 bsp                               bsp.cpp                22  0x4368bc       
19 main                              main.cpp               61  0x43c7d0       
mvives
Techie
 
Posts: 15
Joined: Thu Jan 07, 2016 5:16 pm

Re: Logging hangs in 2987+

Postby DanKegel » Tue Jul 25, 2017 7:07 pm

I'm seeing something very similar, might not be same root cause, but I'll reply here anyway because of the similar stack. I have a local build of cef built with

Code: Select all
  export CEF_USE_GN=1
  export GN_DEFINES="is_official_build=true use_sysroot=false use_allocator=none symbol_level=1"
  export GYP_DEFINES="disable_nacl=1 use_sysroot=0 buildtype=Official use_allocator=none"
  export CEF_ARCHIVE_FORMAT=tar.bz2
  python automate-git.py --minimal-distrib --client-distrib --force-clean --x64-build --build-target=cefsimple \
    --url="$(pwd)/.git" \
    --download-dir="$(pwd)/tmp/downloadedsrc" \
    --branch="$CEFBRANCH"


Our client app worked with 2704 (which may have been built with slightly different options,
see https://bitbucket.org/chromiumembedded/ ... buntu-1604),
but hangs in CefInitialize with 3112:

Code: Select all
(gdb) bt
#0  0x00007fffebe67a4f in futex_wait (private=0, expected=1, futex_word=0x7ffff5c51df0 <content::g_libc_localtime_funcs_guard>) at ../sysdeps/unix/sysv/linux/futex-internal.h:61
#1  futex_wait_simple (private=0, expected=1, futex_word=0x7ffff5c51df0 <content::g_libc_localtime_funcs_guard>) at ../sysdeps/nptl/futex-internal.h:135
#2  __pthread_once_slow (once_control=0x7ffff5c51df0 <content::g_libc_localtime_funcs_guard>, init_routine=0x7fffed7c5fa0 <InitLibcLocaltimeFunctions()>) at pthread_once.c:105
#3  0x00007fffed7c6151 in localtime_r () at ../../content/zygote/zygote_main_linux.cc:285
#4  0x00007fffeece0c56 in Init () at ../../base/logging.cc:808
#5  0x00007fffed7c6063 in InitLibcLocaltimeFunctions () at ../../content/zygote/zygote_main_linux.cc:207
#6  0x00007fffebe67a99 in __pthread_once_slow (once_control=0x7ffff5c51df0 <content::g_libc_localtime_funcs_guard>, init_routine=0x7fffed7c5fa0 <InitLibcLocaltimeFunctions()>) at pthread_once.c:116
#7  0x00007fffed7c6151 in localtime_r () at ../../content/zygote/zygote_main_linux.cc:285
#8  0x00007fffeece0c56 in Init () at ../../base/logging.cc:808
#9  0x00007fffef9b177e in LoadLocaleResources () at ../../ui/base/resource/resource_bundle.cc:353
#10 0x00007fffef9b1128 in InitSharedInstanceWithLocale () at ../../ui/base/resource/resource_bundle.cc:204
#11 0x00007fffeec2d492 in InitializeResourceBundle () at ../../cef/libcef/common/main_delegate.cc:662
#12 0x00007fffeec2cc15 in PreSandboxStartup () at ../../cef/libcef/common/main_delegate.cc:531
#13 0x00007fffeeb4e7cd in Initialize () at ../../content/app/content_main_runner.cc:646
#14 0x00007ffff07f136f in MainInitialize () at ../../services/service_manager/embedder/main.cc:435
#15 0x00007fffeeb9186b in Initialize () at ../../cef/libcef/browser/context.cc:382
#16 0x00007fffeeb91508 in CefInitialize () at ../../cef/libcef/browser/context.cc:235
#17 0x00007fffed2422a5 in cef_initialize () at ../../cef/libcef_dll/libcef_dll.cc:227
#18 0x00007ffff7a720a8 in CefInitialize (args=..., settings=..., application=..., windows_sandbox_info=0x0)
    at /home/buildbot/slave-state/ubu1604/g-speak-rbb-ubu1604-9-ubu1604/oblong-cef-ubu1604-rel-3_3112-yobuild11/build/btmp/cef_binary_3.3112.1649.g7bc3395_linux64/libcef_dll/wrapper/libcef_dll_wrapper.cc:221
#19 0x00007ffff7a30b15 in initialize_cef (wt_settings=...)


In both your stack trace and mine, it looks like this line in zygote_main_linux.cc's localtime_r() is recursing
because it calls LOG(), and the nested call to pthread_once in

CHECK_EQ(0, pthread_once(&g_libc_localtime_funcs_guard,
InitLibcLocaltimeFunctions));

hangs. Using gdb, I verified that this is the LOG that triggers the recursion:

Code: Select all
static void InitLibcLocaltimeFunctions() {
  g_libc_localtime = reinterpret_cast<LocaltimeFunction>(
      dlsym(RTLD_NEXT, "localtime"));
  ...
  if (!g_libc_localtime || !g_libc_localtime_r) {
    // http://code.google.com/p/chromium/issues/detail?id=16800
    //
    // Nvidia's libGL.so overrides dlsym for an unknown reason and replaces
    // it with a version which doesn't work. In this case we'll get a NULL
    // result. There's not a lot we can do at this point, so we just bodge it!
    LOG(ERROR) << "Your system is broken: dlsym doesn't work! This has been "
                  "reported to be caused by Nvidia's libGL. You should expect"
                  " time related functions to misbehave. "
                  "http://code.google.com/p/chromium/issues/detail?id=16800";
  }


which is strange. The libGL bug that refers to was fixed ages ago, and I'm not using nvidia anyway.

Stepping through dlsym verifies that it's returning null:
Code: Select all
(gdb} break dlsym
(gdb) finish
Run till exit from #0  __dlsym (handle=<optimized out>, name=<optimized out>) at dlsym.c:74
InitLibcLocaltimeFunctions () at ../../content/zygote/zygote_main_linux.cc:192
192   ../../content/zygote/zygote_main_linux.cc: No such file or directory.
Value returned is $4 = (void *) 0x0


(sudo apt source glibc gets the matching source nicely, and dir /home/dank/xsrc/glibc-2.23/dlfcn let list work.)

So, uh, I dunno. I guess I should try building cef with use_sysroot=1 etc. instead to get back into the path more travelled.
DanKegel
Mentor
 
Posts: 59
Joined: Fri Nov 08, 2013 12:46 pm

Re: Logging hangs in 2987+

Postby DanKegel » Thu Jul 27, 2017 8:11 pm

zygote_main_linux.cc says "Since we will be first in the dynamic resolution order..."
and indeed, ldd cefclient shows libcef.so is first (well, second, after vdso).
But my app is different: ldd on it shows
...
libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007fc2e110b000)
libcef.so => /opt/oblong/deps-64-11/cef3112/Debug/libcef.so (0x00007fc2d7949000)
libX11.so.6 => /usr/lib/x86_64-linux-gnu/libX11.so.6 (0x00007fc2d760f000)
...

Thus the dlsym(RTLD_NEXT, "localtime") fails, because the lookup starts with libX11
and never gets to libc.

So there's something fishy about how my app is linked. zygote_main_linux.cc
could take countermeasures (e.g. dlopen("libc.so.6")) to protect itself against
that, but that's not the chromium way.

These two things seem to help:
a) put -lcef first on the list of libraries to link against, and if that's not enough,
b) replace -lcef with
-Wl,--no-as-needed -lcef -Wl,--as-needed
to force the app to put libcef.so in the shared library search list
used by dlsym()
Doing that causes libcef.so to show up much higher in the output of ldd,
and gets me past the hang and onto the next problem.
DanKegel
Mentor
 
Posts: 59
Joined: Fri Nov 08, 2013 12:46 pm

Re: Logging hangs in 2987+

Postby magreenblatt » Thu Jul 27, 2017 9:34 pm

What if you do "LD_PRELOAD=libcef.so yourapp"?
magreenblatt
Site Admin
 
Posts: 12383
Joined: Fri May 29, 2009 6:57 pm

Re: Logging hangs in 2987+

Postby DanKegel » Fri Jul 28, 2017 11:24 am

LD_PRELOAD gets past the problem, as predicted (but oddly causes sh to crash if you try to use it with ldd).

I'm testing a patch to fix the hang:

+--- content/zygote/zygote_main_linux.cc
++++ content/zygote/zygote_main_linux.cc
+@@ -201,13 +201,24 @@ static void InitLibcLocaltimeFunctions() {
+ if (!g_libc_localtime || !g_libc_localtime_r) {
...
+- LOG(ERROR) << "Your system is broken: dlsym doesn't work! This has been "
+- "reported to be caused by Nvidia's libGL. You should expect"
+- " time related functions to misbehave. "
+- "http://code.google.com/p/chromium/issues/detail?id=16800";
...
++ const char kMessage[] =
++ "dlsym(RTLD_NEXT, ...) failed to find glibc!\n"
++ "This may be caused by old versions of Nvidia's libGL.\n"
++ "It may also be caused by listing -lcef too late when linking.\n"
++ "You should expect time related functions to misbehave.\n"
++ "http://code.google.com/p/chromium/issues/detail?id=16800\n";
++ ignore_result(write(STDERR_FILENO, kMessage, sizeof(kMessage) - 1));
DanKegel
Mentor
 
Posts: 59
Joined: Fri Nov 08, 2013 12:46 pm

Re: Logging hangs in 2987+

Postby DanKegel » Fri Jul 28, 2017 1:16 pm

Note: see also https://bitbucket.org/chromiumembedded/ ... yerupdater for another symptom of cef not showing up first in 'ldd ./myapp'
DanKegel
Mentor
 
Posts: 59
Joined: Fri Nov 08, 2013 12:46 pm

Previous

Return to Support Forum

Who is online

Users browsing this forum: Majestic-12 [Bot], TakashiHSD and 40 guests