Re: How does one debug uninitialized value usage from JavaScript (TB) ?

ISHIKAWA, Chiaki Fri, 01 Feb 2013 10:15:23 -0800

(2013/01/30 11:21), ISHIKAWA, Chiaki wrote:

(2013/01/29 19:03), Julian Seward wrote:

From: "Chiaki ISHIKAWA" <[email protected]>
I could allocate 6 GB to linux 64 bits images for ordinary program
execution on my PC
But debug build of TB with all the symbols and such causes the memory
usage (including the loading of symbols)


I am surprised to hear this.  Using a 64-bit build of Firefox, I can
do a complete mochitests run on Valgrind/Memcheck in about 12 CPU
hours and about 4GB RSS (4.7 GB total process size).

If you can send me details of how to build TB and run the tests
in question, I can give it a try.  Valgrind has a built-in space
profiling framework, so it's not difficult to see if some aspect
of it is using more space than it should.

J


I am going to double check what I did, and
if I dont find that I made a glaring error (or errors) in creating and
running TB under memcheck on top of 64 bit linux (Debian GNU/Linux), I am
going to send you what I did (so that you can re-try my situation.).

Could it be that TB, because of the nature of its composition, has all the code
of browser AND mail-related protocol support, and thus inherently
much larger than FF browser if we include all the dynamically
library routines? : POP3, and SMTP is smallish, but IMAP
is complex enough, and on top of that, it has the local mail store which is
rather huge in terms of code support. One of these days, TB seems to have an 
almost
full browser support as well. [It may not have the full GUI for browswer 
support, but
rendering and https: support, etc. are all there.])

Oh, one thing I noticed: during earlier debugging, I missed many symbols for 
external libraries.
But I found out that Debian releases the symbols for these libraries as 
separate packages.
Once I installed these symbol packages, I could get a reasonably detailed 
symbolic dumps
for memory access.
It could be that if I remove symbols for not-so-interesing libraries to
focus on only the binaries produced by TB source files, I may be able to
run memcheck in tight memory of my PC. I will investigate this avenue as well.


TIA


(Sorry for a lengthy post).

OK, I am running the "make mozmill" test of
debug build of TB under 64-bit Debian GNU/Linux.
(I have not gotten around to create a non-debug build to run under memcheck yet.
I wanted to compare the speed with the past 32-bit debug build TB run under 
memcheck
under 32-bit linux.)

The session has been running for more than 13 hours now,
Since it takes almost 23 hours (yes, I just checked the past session log 
carefully)
under 32-bit linux to run "make mozmill" run
of TB (debug build) with my wrapper program, it is still too early
to tell whether we gained much speed or not, but
I think I have not seen dramatic speed increase yet.
This is based on seeing the TB windows come and go during the test :-)

In my MOZCONFIG, I have the following snippet:

ac_add_options --enable-valgrind
ac_add_options --enable-optimize="-g -O -freorder-blocks"
ac_add_options --disable-jemalloc

<=== Maybe I should be adventurous and use "-O2" instead of "-O"?
[ But these options are exactly the same under 32-bit linux !
Should I turn on -O2? Come to think of it, I would gain much more
under 64 bit compilation model due to the abundance of registers(?)]]

Anyway, a couple of interesting bug discoveries under 64-bit version.

Below are two new bugs that appear in 64 bits linux check of TB using
memcheck.  (They were not observed in 32 bit linux, but note that I am
using a relatively unpatched (not patched by my local fixes that were
applied to 32bits test) version of TB. I will try to synchronize the
two source trees. Nevertheless, since running valgrind for the last
two months or so, these bugs were not observed under 32 bits version.


The source file versions were:
comm-central:
/home/ishikawa/TB-NEW/TB-3HG/new-src
hg identify
90fb92893b25+ tip

mozilla subdirectory repository
/home/ishikawa/TB-NEW/TB-3HG/new-src/mozilla
hg identify
20bbf73921f4+ tip

[1] Reference to NULL (0x0) address when 4 bytes entity is written.
(This never happened in 32bit version.)
A single error occurence.

Admittedly, it is in DEBUG code, but it seems some underlying assumption
in the code behavior is invalidated (under some error conditions?).

Below, the quoted piece of session log has sanitized traceback using
comm-central's mozilla/tools/rb/fix-linux-stack.pl (it seems
mozilla-central has this script under a directory with a slightly
different name.)
The line numbers may be slightly off due to local modification.

mozilla/storage/src/mozStorageService.cpp:828

    #ifdef DEBUG
        nsTArray<nsRefPtr<Connection> > connections;
        getConnections(connections);
        for (uint32_t i = 0, n = connections.Length(); i < n; i++) {
828=>          MOZ_ASSERT(!connections[i]->ConnectionReady());
        }
    #endif

   [...]

WARNING: GetDefaultCharsetForLocale: need to add multi locale support: file/home/ishikawa/TB-NEW/TB-3HG/new-src/mozilla/intl/locale/src/unix/nsUNIXCharset.cpp, line 105Assertion failure: !connections[i]->ConnectionReady(), at/home/ishikawa/TB-NEW/TB-3HG/new-src/mozilla/storage/src/mozStorageService.cpp:828

==9480== Invalid write of size 4

==9480== at 0x94B7736: mozilla::storage::Service::Observe(nsISupports*, char const*, unsigned short const*)(mozStorageService.cpp:828)==9480== by 0x9F889B1: nsObserverList::NotifyObservers(nsISupports*, char const*, unsigned short const*)(nsObserverList.cpp:99)==9480== by 0x9F8930E: nsObserverService::NotifyObservers(nsISupports*, char const*, unsigned short const*)(nsObserverService.cpp:161)

==9480==    by 0x9F6FBE7: mozilla::ShutdownXPCOM(nsIServiceManager*) 
(nsXPComInit.cpp:562)
==9480==    by 0x9F705F5: NS_ShutdownXPCOM_P (nsXPComInit.cpp:513)
==9480==    by 0x80C6516: ScopedXPCOMStartup::~ScopedXPCOMStartup() 
(nsAppRunner.cpp:1124)
==9480==    by 0x80D12B8: XREMain::XRE_main(int, char**, nsXREAppData const*) 
(nsAppRunner.cpp:3915)
==9480==    by 0x80D1644: XRE_main (nsAppRunner.cpp:4093)
==9480==    by 0x401F1D: main (nsMailApp.cpp:111)
==9480==  Address 0x0 is not stack'd, malloc'd or (recently) free'd
==9480==
{
   <insert_a_suppression_name_here>
   Memcheck:Addr4
   fun:_ZN7mozilla7storage7Service7ObserveEP11nsISupportsPKcPKt
   fun:_ZN14nsObserverList15NotifyObserversEP11nsISupportsPKcPKt
   fun:_ZN17nsObserverService15NotifyObserversEP11nsISupportsPKcPKt
   fun:_ZN7mozilla13ShutdownXPCOMEP17nsIServiceManager
   fun:NS_ShutdownXPCOM_P
   fun:_ZN18ScopedXPCOMStartupD1Ev
   fun:_ZN7XREMain8XRE_mainEiPPcPK12nsXREAppData
   fun:XRE_main
   fun:main
}

Program 
/home/ishikawa/TB-NEW/TB-3HG/objdir-tb3/mozilla/dist/bin/thunderbird-bin (pid = 
9480) received signal 11.
Stack:
__restore_rt (sigaction.c:0)

mozilla::storage::Service::Observe(nsISupports*, char const*, unsigned short const*)(/home/ishikawa/TB-NEW/TB-3HG/new-src/mozilla/storage/src/mozStorageService.cpp:828)nsObserverList::NotifyObservers(nsISupports*, char const*, unsigned short const*)(/home/ishikawa/TB-NEW/TB-3HG/new-src/mozilla/xpcom/ds/nsObserverList.cpp:98)nsTHashtable<nsObserverList>::GetEntry(char const*) const(/home/ishikawa/TB-NEW/TB-3HG/objdir-tb3/mozilla/xpcom/ds/../../dist/include/nsTHashtable.h:141)

mozilla::ShutdownXPCOM(nsIServiceManager*) 
(/home/ishikawa/TB-NEW/TB-3HG/new-src/mozilla/xpcom/build/nsXPComInit.cpp:564)
NS_ShutdownXPCOM_P 
(/home/ishikawa/TB-NEW/TB-3HG/new-src/mozilla/xpcom/build/nsXPComInit.cpp:514)
ScopedXPCOMStartup::~ScopedXPCOMStartup() 
(/home/ishikawa/TB-NEW/TB-3HG/new-src/mozilla/toolkit/xre/nsAppRunner.cpp:1125)
operator delete 
(/home/ishikawa/TB-NEW/TB-3HG/objdir-tb3/mozilla/toolkit/xre/../../dist/include/mozilla/mozalloc.h:224)
XRE_main 
(/home/ishikawa/TB-NEW/TB-3HG/new-src/mozilla/toolkit/xre/nsAppRunner.cpp:4093)
do_main (/home/ishikawa/TB-NEW/TB-3HG/new-src/mail/app/nsMailApp.cpp:111)
__libc_start_main (/home/aurel32/eglibc/eglibc-2.13/csu/libc-start.c:260)
_start 
(/home/ishikawa/TB-NEW/TB-3HG/objdir-tb3/mozilla/dist/bin/thunderbird-bin)
Sleeping for 300 seconds.

Type 'gdb /home/ishikawa/TB-NEW/TB-3HG/objdir-tb3/mozilla/dist/bin/thunderbird-bin 9480' to attach your debugger to thisthread.

Done sleeping...



[2] iconv failure error(s)

This one is a suprise.
Many repetition in different test targets in "make mozmill"
(Again, I don't think I saw these errors in 32 bits test so often.
These errors seem to happen near the shutdown of TB and
when TB seems to write something to the console. Strange indeed.)

I set
  LANG=C
  LC_ALL=C

  export LANG
  export LC_ALL

near the beginning of script to run "make mozmill" test.

I checked the default LANG and LC_ALL setting just in case.  under 64-bit Debian
GNU/Linux: LANG=ja_JP.UTF-8, LC_ALL seems to be empty.  or not set.
These are the same settings under 32-bit Debian GNU/Linux of my
installation.
So I have no idea why we have this strange iconv error under 64-bits.


/TB-NEW/TB-3HG/new-src/mozilla/xpcom/io/nsNativeCharsetUtils.cpp

        if (gUnicodeToNative != INVALID_ICONV_T) {
            res = xp_iconv(gUnicodeToNative, (const char **) input, &inLeft, 
output, &outLeft);

            *inputLeft = inLeft / 2;
            *outputLeft = outLeft;
            if (res != (size_t) -1) {
                return NS_OK;
            }

541=>       NS_ERROR("iconv failed");


/home/ishikawa/TB-NEW/TB-3HG/new-src/mozilla/xpcom/io/nsNativeCharsetUtils.cpp:146
(Below line number is off due to, I suppose, "inline" nature of the function.)

    static inline void
    xp_iconv_reset(iconv_t converter)
    {
        // NOTE: the man pages on Solaris claim that you can pass NULL
        // for all parameter to reset the converter, but beware the
        // evil Solaris crash if you go down this route >:-)

146=>        const char *zero_char_in_ptr  = NULL;
        char       *zero_char_out_ptr = NULL;
        size_t      zero_size_in      = 0,
                    zero_size_out     = 0;

        xp_iconv(converter, &zero_char_in_ptr,
                            &zero_size_in,
                            &zero_char_out_ptr,
                            &zero_size_out);
    }

[As I write this submission, I realized that xp_iconv_reset() does not
check the return value of xp_iconv(). This is BAD in principle, isn't it?!
Yeah, initialization can't fail, right? But I suspect something went wrong here.
Maybe we have not noticed the iconv() reset failure problem because of this?]

/home/ishikawa/TB-NEW/TB-3HG/new-src/mozilla/xpcom/io/nsNativeCharsetUtils.cpp:831
        while (bufLeft) {
            char *p = temp;
            uint32_t tempLeft = sizeof(temp);
831=>       nsresult rv = conv.UnicodeToNative(&buf, &bufLeft, &p, &tempLeft);
            if (NS_FAILED(rv)) return rv;

            if (tempLeft < sizeof(temp))
                output.Append(temp, sizeof(temp) - tempLeft);
        }


/home/ishikawa/TB-NEW/TB-3HG/new-src/mozilla/toolkit/xre/nsConsoleWriter.cpp:88

      for (uint32_t i = 0; i < mcount; ++i) {
        rv = messages[i]->GetMessageMoz(getter_Copies(msg));
        if (NS_SUCCEEDED(rv)) {
          NS_CopyUnicodeToNative(msg, nativemsg);
88 =      PR_fprintf(file, "%s" NS_LINEBREAK, nativemsg.get());
        }
        NS_IF_RELEASE(messages[i]);
      }

/home/ishikawa/TB-NEW/TB-3HG/new-src/mozilla/toolkit/xre/nsAppRunner.cpp:1124

        gDirServiceProvider->DoShutdown();
        SAMPLE_MARKER("Shutdown early");

        WriteConsoleLog();

1124=>  NS_ShutdownXPCOM(mServiceManager);
        mServiceManager = nullptr;
      }

BTW, xp_iconv() is defined thusly:
static inline size_t
xp_iconv(iconv_t converter,
         const char **input,
         size_t      *inputLeft,
         char       **output,
         size_t      *outputLeft)
{
    size_t res, outputAvail = outputLeft ? *outputLeft : 0;
    res = iconv(converter, ICONV_INPUT(input), inputLeft, output, outputLeft);
    if (res == (size_t) -1) {
        // on some platforms (e.g., linux) iconv will fail with
        // E2BIG if it cannot convert _all_ of its input.  it'll
        // still adjust all of the in/out params correctly, so we
        // can ignore this error.  the assumption is that we will
        // be called again to complete the conversion.
        if ((errno == E2BIG) && (*outputLeft < outputAvail))
            res = 0;
    }
    return res;
}

The typical assertion error.