1036286 - Firefox on Android L unexpectedly exit by sighandler

Status: VERIFIED FIXED

(Firefox for Android Graveyard :: General, defect)

Description

[Makoto Kato [:m_kato]]

Even if landing bug 1030899, Firefox on Android L unexpectedly exits.  If disabling signal handler (sDisableSignalHandling in profile/dirserviceprovider/src/nsProfileLock.cpp = true), it isn't exited.

Comment 1

[Makoto Kato [:m_kato]]

this signal handler is for bug 76431, but Android version cannot share profile...

Comment 2

[Benjamin Smedberg]

What signal is being handled here?

The signal handler here is just supposed to be a last-ditch correction before we crash to unlock the profile. In general if we've hit the signal handler, the fatal error is already present.

Comment 3

[Sylvestre Ledru [:Sylvestre]]

Not tracking for 31. It is too late for the Android L now. However, we could take the fixes in 32.

Comment 4

[Makoto Kato [:m_kato]]

This issue depends on custom linker.  At first, SEGVHandler::handler catches SEGSEGV, then it load code without error.  But, after that another sighandler of profile catches it with same si_addr.  So process is exited by exit().

Comment 5

[Brad Lassey [:blassey] (use needinfo?)]

Glandium, see comment 4

Comment 6

[Mike Hommey [:glandium]]

Please attach logs with MOZ_DEBUG_LINKER set to 1.

Comment 7

[Brad Lassey [:blassey] (use needinfo?)]

Makoto, can you provide the logs glandium asked for?

Comment 8

[Chris B]

Attachment: MOZ_DEBUG_LINKER.txt

I have been observing the progress of bugs relating to the Android L Preview and wwould like to try to help accelerate the process. Hopefully this log is what you guys needed.

Comment 9

[Brad Lassey [:blassey] (use needinfo?)]

Glandium, see the attached logs

Comment 10

[Mike Hommey [:glandium]]

This log doesn't show anything problematic at the linker level, and doesn't match what Makoto described.

Comment 11

[Chris B]

Some additional information. The device I am testing from is a Nexus 5. The build I gathered the log from was nightly http://ftp.mozilla.org/pub/mozilla.org/mobile/nightly/latest-mozilla-central-android/fennec-33.0a1.multi.android-arm.apk on 7/16/14 (today) since as I understand bug 1030899 is already patched in all builds 32+. 

I gathered the log by starting firefox with "adb shell am start -a android.activity.MAIN -n org.mozilla.fennec/.App --es env0 MOZ_DEBUG_LINKER=1" and simply having adb logcat write to file in the background. 

If I have done something incorrectly or if there is anything else that I could be instructed to try I would be glad to continue helping.

Comment 12

[Makoto Kato [:m_kato]]

(In reply to Mike Hommey [:glandium] from comment #10)
> This log doesn't show anything problematic at the linker level, and doesn't
> match what Makoto described.

This problem occurs when installing multiple signal handlers. If nsProfileLock::FatalSignalHandler() catches SIGSEGV for custom linker, this signal handler function will call exit() even if that SIGSEGV should handle custom linker only.

So adb log show the following.

I/        ( 1477): Process 32017 exited due to signal (11)


On my debug build, when it accesses PumpMessage::PumpMessage() by new MessageLoopForUI into NS_InitXPCOM2 (the page around this function isn't loaded yet), nsProfileLock::FatalSignalHandler will call exit() after old signal handler on custom linker.

Of course, when I turn off dynamic load of customer linker (modify signalHandlingSlow=true), no SIGSEGV on NS_InitXPCOM2.

But since libart installs another signal handler, ART JIT code causes signal, then nsProfileLock::FatalSignalHandler will call exit()...

I think that Android cannot share user profile, so is it unnecessary to lock profile?

Comment 13

[Mike Hommey [:glandium]]

There are reasons why I'm asking for a log with MOZ_DEBUG_LINKER=1, so please do so.

Comment 14

[Makoto Kato [:m_kato]]

Attachment: MOZ_DEBUG_LINKER=1

Comment 15

[Makoto Kato [:m_kato]]

Attachment: MOZ_DEBUG_LINKER=1 with adding trace for nsProfileLock::FatalSignalHandler

Add trace version.

diff --git a/profile/dirserviceprovider/src/nsProfileLock.cpp b/profile/dirserviceprovider/src/nsProfileLock.cpp
--- a/profile/dirserviceprovider/src/nsProfileLock.cpp
+++ b/profile/dirserviceprovider/src/nsProfileLock.cpp
@@ -119,16 +119,18 @@ static struct sigaction SIGSEGV_oldact;
 static struct sigaction SIGTERM_oldact;
 
 void nsProfileLock::FatalSignalHandler(int signo
 #ifdef SA_SIGINFO
                                        , siginfo_t *info, void *context
 #endif
                                        )
 {
+    __android_log_print(ANDROID_LOG_INFO, "Gecko", "Entering nsProfileLock::FatalSignalHandler");
+
     // Remove any locks still held.
     RemovePidLockFiles(true);
 
     // Chain to the old handler, which may exit.
     struct sigaction *oldact = nullptr;
 
     switch (signo) {
       case SIGHUP:
@@ -172,26 +174,28 @@ void nsProfileLock::FatalSignalHandler(i
 
             sigprocmask(SIG_UNBLOCK, &unblock_sigs, nullptr);
 
             raise(signo);
         }
 #ifdef SA_SIGINFO
         else if (oldact->sa_sigaction &&
                  (oldact->sa_flags & SA_SIGINFO) == SA_SIGINFO) {
+            __android_log_print(ANDROID_LOG_INFO, "Gecko", "nsProfileLock::FatalSignalHandler is calling sa_sigaction=%p", oldact->sa_sigaction);
             oldact->sa_sigaction(signo, info, context);
         }
 #endif
         else if (oldact->sa_handler && oldact->sa_handler != SIG_IGN)
         {
             oldact->sa_handler(signo);
         }
     }
 
     // Backstop exit call, just in case.
+    __android_log_print(ANDROID_LOG_INFO, "Gecko", "nsProfileLock::FatalSignalHandler is calling _exit(%d)", signo);

Comment 16

[Mike Hommey [:glandium]]

Can you attach a new debug log with the following patch applied?

diff --git a/mozglue/linker/CustomElf.cpp b/mozglue/linker/CustomElf.cpp
--- a/mozglue/linker/CustomElf.cpp
+++ b/mozglue/linker/CustomElf.cpp
@@ -737,16 +737,17 @@ CustomElf::Relocate()
     if (symtab_index != ELF_R_SYM(rel->r_info)) {
       symtab_index = ELF_R_SYM(rel->r_info);
       const Sym sym = symtab[symtab_index];
       if (sym.st_shndx != SHN_UNDEF) {
         symptr = GetPtr(sym.st_value);
       } else {
         /* TODO: handle symbol resolving to nullptr vs. being undefined. */
         symptr = GetSymbolPtrInDeps(strtab.GetStringAt(sym.st_name));
+       DEBUG_LOG("Resolved %s to %p", strtab.GetStringAt(sym.st_name), symptr);
       }
     }
 
     if (symptr == nullptr)
       WARN("%s: Relocation to NULL @0x%08" PRIxAddr,
           GetPath(), rel->r_offset);
 
     /* Apply relocation */
diff --git a/mozglue/linker/ElfLoader.cpp b/mozglue/linker/ElfLoader.cpp
--- a/mozglue/linker/ElfLoader.cpp
+++ b/mozglue/linker/ElfLoader.cpp
@@ -919,16 +919,17 @@ Divert(T func, T new_func)
     start = trampoline + 6;
   }
 
   size_t len = sizeof(trampoline) - (start - trampoline);
   EnsureWritable w(reinterpret_cast<void *>(addr), len + sizeof(void *));
   memcpy(reinterpret_cast<void *>(addr), start, len);
   *reinterpret_cast<void **>(addr + len) = FunctionPtr(new_func);
   cacheflush(addr, addr + len + sizeof(void *), 0);
+  DEBUG_LOG("Diverting function @%p", reinterpret_cast<void *>(addr));
   return true;
 #else
   return false;
 #endif
 }
 #else
 #define sys_sigaction sigaction
 template <typename T>

Comment 17

[Makoto Kato [:m_kato]]

Attachment: MOZ_DEBUG_LINKER=1 with commnet #16

Comment 18

[Mike Hommey [:glandium]]

(In reply to Makoto Kato (:m_kato) from comment #17)
> Created attachment 8457825 [details]
> MOZ_DEBUG_LINKER=1 with commnet #16

This message:
+  DEBUG_LOG("Diverting function @%p", reinterpret_cast<void *>(addr));

doesn't show up in your log. Can you figure why?

Comment 19

[Makoto Kato [:m_kato]]

humm, rebuild with clobber.

Comment 20

[Makoto Kato [:m_kato]]

It seems to be too early point to output log.  Because it cannot output "SEGVHandler latency" too and SEGVHandler instance is global value.

glandium, is "SEGVHandler latency" outputed on your device?

Comment 21

[Mike Hommey [:glandium]]

(In reply to Makoto Kato (:m_kato) from comment #20)
> It seems to be too early point to output log.  Because it cannot output
> "SEGVHandler latency" too and SEGVHandler instance is global value.
> 
> glandium, is "SEGVHandler latency" outputed on your device?

Interestingly, no.

Comment 22

[Makoto Kato [:m_kato]]

Attachment: MOZ_DEBUG_LINKER=1 with commnet #16

always true on isVerbose() at force.

I confirmed the following is logged.

I/GeckoLinker(27972): Diverting function @0xb6f60770

Comment 23

[Mike Hommey [:glandium]]

Could you attach a new log for the same build, including the Diverting function message, as well as a copy of /system/lib/libc.so and a dump of /proc/$pid/maps for the fennec process (which, obviously, you'd need to get before the crash ; you may want to open(/proc/self/maps) and dump its content from fennec itself)

Comment 24

[Makoto Kato [:m_kato]]

Attachment: /proc/*/maps

Comment 25

[Makoto Kato [:m_kato]]

Attachment: libc.so on Android L

Comment 26

[Makoto Kato [:m_kato]]

Attachment: logcat

Comment 27

[Mike Hommey [:glandium]]

Attachment: Make sure libraries loaded by faulty.lib use its own sigaction

Android L added a libsigchain library it LD_PRELOADs. That library exposes
a different sigaction than libc's. It's used for ART.

faulty.lib gets its sigaction from libsigchain, but after bug 874708, the
libraries it loads simply use libc's sigaction, assuming it would be the
hooked one. In turn, this means libraries loaded by faulty.lib may
override faulty.lib's handler, which is definitely not the intent.

This essentially restores some of the code that bug 874708 removed.

An alternative fix would be to add support for LD_PRELOAD, but that has more
implications and feels more risky. This could be done, if necessary, as a
followup.

Comment 28

[Mike Hommey [:glandium]]

Comment on attachment 8461188 [details] [diff] [review]
Make sure libraries loaded by faulty.lib use its own sigaction

Makoto-san, can you test this patch?

Comment 29

[Nathan Froyd [:froydnj]]

Comment on attachment 8461188 [details] [diff] [review]
Make sure libraries loaded by faulty.lib use its own sigaction

Review of attachment 8461188 [details] [diff] [review]:
-----------------------------------------------------------------

Is this going to break the Samsung GS4 case that bug 874708 was partly trying to address?

Comment 30

[Mike Hommey [:glandium]]

(In reply to Nathan Froyd (:froydnj) from comment #29)
> Is this going to break the Samsung GS4 case that bug 874708 was partly
> trying to address?

No, because it doesn't remove the hook into the system sigaction.

Comment 31

[Mike Hommey [:glandium]]

(the problem in that bug was that a system-linker-loaded library was calling the system sysaction ; the patch here only affects faulty.lib-loaded libraries)

Comment 32

[Makoto Kato [:m_kato]]

Attachment: logcat w/ glandium's fix

Initializing XPCOM works fine. But then, Fennec still exits by exit().

Before calling ART's signal handler, signal seems to be dispatched to nsProfileLock's signal handler.  so it calls exit()....

Comment 33

[Makoto Kato [:m_kato]]

Comment on attachment 8461188 [details] [diff] [review]
Make sure libraries loaded by faulty.lib use its own sigaction

initialization of XPCOM works fine, but nsProfileLock's signal handler still catches SIGSEGV for ART?. so Fennec exits unexpectedly.  I attach logcat file.

Comment 34

[Mike Hommey [:glandium]]

(In reply to Makoto Kato (:m_kato) from comment #32)
> Created attachment 8461276 [details]
> logcat w/ glandium's fix
> 
> Initializing XPCOM works fine. But then, Fennec still exits by exit().
> 
> Before calling ART's signal handler, signal seems to be dispatched to
> nsProfileLock's signal handler.  so it calls exit()....

Actually, there's progress, because now the linker *is* catching a segfault and dispatching it to the nsProfileLock's signal handler, as it's supposed to do.

I/GeckoLinker( 8775): Caught segmentation fault @0x0
I/GeckoLinker( 8775): Redispatching to registered handler @0x5a4288fd

So, now, you'd need to figure out what /that/ segfault actually is.

The good thing is that if I land this, the next nightly that has the patch in it should trigger the crash reporter and give a proper crash report. So let's land this.

Comment 35

[Mike Hommey [:glandium]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/34235900c3a0

Comment 36

[Makoto Kato [:m_kato]]

(In reply to Mike Hommey [:glandium] from comment #34)

> The good thing is that if I land this, the next nightly that has the patch
> in it should trigger the crash reporter and give a proper crash report. So
> let's land this.

Since nsProfileLock's signal handler calls exit(), we may not be able to get crash by crash reporter.

Comment 37

[Mike Hommey [:glandium]]

(In reply to Makoto Kato (:m_kato) from comment #36)
> Since nsProfileLock's signal handler calls exit(), we may not be able to get
> crash by crash reporter.

Local builds don't have the crash reporter enabled by default.

Comment 38

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/34235900c3a0

Comment 39

[Makoto Kato [:m_kato]]

(In reply to Mike Hommey [:glandium] from comment #37)
> Local builds don't have the crash reporter enabled by default.

Although I test the latest Nightly, it doesn't launch crash reporter due to comment #36.  When nsProfileLock's signal handler is called, oldact->sa_handler isn't SIG_DFL.

Comment 40

[Mike Hommey [:glandium]]

(In reply to Makoto Kato (:m_kato) from comment #39)
> (In reply to Mike Hommey [:glandium] from comment #37)
> > Local builds don't have the crash reporter enabled by default.
> 
> Although I test the latest Nightly, it doesn't launch crash reporter due to
> comment #36.  When nsProfileLock's signal handler is called,
> oldact->sa_handler isn't SIG_DFL.

And when oldact->sa_handler isn't SIG_DFL, oldact->sa_sigaction or oldact->sa_handler are called before exit, and one of those should be the crash reporter's. Note something fishy is likely to be happening with the ART segfault handler being registered before any of all that. Anyways, there's still a null deref crash that needs to be identified. The fact that segfault handling is kind of screwed up doesn't change much about that... except if the null deref comes from ART...

Comment 41

[Mike Hommey [:glandium]]

Makoto-san, can you test this build?
http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/[e-mail]-ce8aa1d9a6a4/try-android/fennec-34.0a1.en-US.android-arm.apk

Comment 42

[epg]

(In reply to Mike Hommey [:glandium] from comment #41)
> Makoto-san, can you test this build?
> http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/[e-mail]-
> ce8aa1d9a6a4/try-android/fennec-34.0a1.en-US.android-arm.apk

Installed last night. Finally have working Firefox on L! Posting this using that apk :)

Thanks.

Comment 43

[Makoto Kato [:m_kato]]

(In reply to Mike Hommey [:glandium] from comment #41)
> Makoto-san, can you test this build?
> http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/[e-mail]-
> ce8aa1d9a6a4/try-android/fennec-34.0a1.en-US.android-arm.apk

It works on Android L.

(In reply to epg from comment #42)
> (In reply to Mike Hommey [:glandium] from comment #41)
> Installed last night. Finally have working Firefox on L! Posting this using
> that apk :)
> 
> Thanks.

thank you for verified.

Comment 44

[Mike Hommey [:glandium]]

Can you test this build? (this one at least doesn't break on older android versions)
http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/[e-mail]-444c8ae1110e/try-android/fennec-34.0a1.en-US.android-arm.apk

Comment 45

[Makoto Kato [:m_kato]]

Attachment: logcat

Fennec is launched, but I cannot navigate to any site. Also, I click menu in Fennec, then process is crashed.

Comment 46

[Makoto Kato [:m_kato]]

Attachment: logcat with MOZ_DEBUG_LINKER=1

Comment 47

[Mike Hommey [:glandium]]

Let's try this one?
http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/[e-mail]-89a9d566cdb1/try-android/fennec-34.0a1.en-US.android-arm.apk

Comment 48

[Makoto Kato [:m_kato]]

(In reply to Mike Hommey [:glandium] from comment #47)
> Let's try this one?
> http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/[e-mail]-
> 89a9d566cdb1/try-android/fennec-34.0a1.en-US.android-arm.apk

It works.

Comment 49

[Mike Hommey [:glandium]]

Backout of the original fix.
https://hg.mozilla.org/integration/mozilla-inbound/rev/350d48e11f31

Comment 50

[Mike Hommey [:glandium]]

Attachment: Delay registration of the faulty.lib signal handler until when it's necessary

It's necessary to delay it because for the second part, we need to call dlopen,
and until recently bionic's linker dead-locked when using dlopen from a static
initializer.

Comment 51

[Mike Hommey [:glandium]]

Attachment: Ensure faulty.lib diverts libc's sigaction instead of a LD_PRELOADed one

and force-send calls to sigaction from faulty.lib-loaded libraries to the libc.

Comment 52

[Ed Morley [:emorley]]

(In reply to Mike Hommey [:glandium] from comment #49)
> Backout of the original fix.
> https://hg.mozilla.org/integration/mozilla-inbound/rev/350d48e11f31

Merge of backout:
https://hg.mozilla.org/mozilla-central/rev/350d48e11f31

Comment 53

[Aaron Train [:aaronmt]]

During the channel meeting we discussed that we'd like to get this on 32.0b6 if at all possible by next week.

Comment 54

[Nathan Froyd [:froydnj]]

Comment on attachment 8467590 [details] [diff] [review]
Delay registration of the faulty.lib signal handler until when it's necessary

Review of attachment 8467590 [details] [diff] [review]:
-----------------------------------------------------------------

::: mozglue/linker/ElfLoader.cpp
@@ +970,5 @@
>  {
>    /* Initialize oldStack.ss_flags to an invalid value when used to set
>     * an alternative stack, meaning we haven't got information about the
> +   * original alternative stack and thus don't mean to restore it in
> +   * the desctructor. */

Nit: "destructor"

@@ +1072,5 @@
>    TmpData *data = reinterpret_cast<TmpData*>(that.stackPtr.get());
>    uint64_t latency = ProcessTimeStamp_Now() - data->crash_timestamp;
>    DEBUG_LOG("SEGVHandler latency: %" PRIu64, latency);
>    /* See bug 886736 for timings on different devices, 150 µs is reasonably above
> +   * the latency on "working" devices and seems to be reasonably fast not to

If you're going to re-word this, maybe "seems to be short enough to not incur..."

Comment 55

[Nathan Froyd [:froydnj]]

Comment on attachment 8467604 [details] [diff] [review]
Ensure faulty.lib diverts libc's sigaction instead of a LD_PRELOADed one

Review of attachment 8467604 [details] [diff] [review]:
-----------------------------------------------------------------

::: mozglue/linker/ElfLoader.cpp
@@ +1026,5 @@
> +
> +#if defined(ANDROID)
> +  /* Android > 4.4 comes with a sigaction wrapper in a LD_PRELOADed library
> +   * (libsigchain) for ART. That wrapper kind of does the same trick as we
> +   * do, so we need extra care in handling it.

Thank you for this comment!

Comment 56

[Mike Hommey [:glandium]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/6bdc1e09802a
https://hg.mozilla.org/integration/mozilla-inbound/rev/5b871cc94344

Comment 57

[Nigel Babu [:nigelb]]

https://hg.mozilla.org/mozilla-central/rev/6bdc1e09802a
https://hg.mozilla.org/mozilla-central/rev/5b871cc94344

Comment 58

[Aaron Train [:aaronmt]]

For what it's worth Google just published LPV81C, new L Preview build

Comment 59

[Mike Hommey [:glandium]]

This should be in last nightly, can you test it?

Comment 60

[Makoto Kato [:m_kato]]

(In reply to Mike Hommey [:glandium] from comment #59)
> This should be in last nightly, can you test it?

The latest Nightly works on Nexus 5/L Preview

Comment 61

[Mike Hommey [:glandium]]

Comment on attachment 8467590 [details] [diff] [review]
Delay registration of the faulty.lib signal handler until when it's necessary

Approval Request Comment
[User impact if declined]: Required for the second patch.
[Describe test coverage new/current, TBPL]: It's been tested before landing, and is now in nightlies.
[Risks and why]: This patch delays the initialization of the signal handler used for on-demand decompression of libraries in Firefox for Android. It doesn't affect neither Firefox desktop nor B2G. This code is exercised before loading any part of Gecko and simply delays that initialization from the moment the java code loads libmozglue.so to the moment the java code loads libxul.so. That initialization is not necessary until libxul.so gets loaded. IOW, risk is very low.
[String/UUID change made/needed]: none

Comment 62

[Mike Hommey [:glandium]]

Comment on attachment 8467604 [details] [diff] [review]
Ensure faulty.lib diverts libc's sigaction instead of a LD_PRELOADed one

Approval Request Comment
[User impact if declined]: Firefox for Android doesn't start at all on Android L (next version of Android)
[Describe test coverage new/current, TBPL]: This was tested before landing and is not on nightlies.
[Risks and why]: This patch changes how sigaction and signal are resolved for libraries we load with our own linker, and how the system sigaction function is hooked. However, in practice, for systems earlier than Android L, the behavior before and after the patch is exactly the same because in all cases, sigaction and signal come from libc.so. IOW, this is almost a no-op for non-Android L, and a fix for Android L. Risk is low.
[String/UUID change made/needed]: none

Comment 63

[Aaron Train [:aaronmt]]

Verified against L Preview LPV81C on my Nexus 7 (2013)

Comment 64

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/3700ed4efa21
https://hg.mozilla.org/releases/mozilla-aurora/rev/2feb0d89cc2e

https://hg.mozilla.org/releases/mozilla-beta/rev/ec230387fad2
https://hg.mozilla.org/releases/mozilla-beta/rev/1f96d584763a