ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00)

ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00)

[Karl Hiramoto]

Hi,

I'm a systemtap newbie.  I get the following error with the 
tcp_trace.stp example and others.

Pass 4: compiled C into "stap_4607b376b916b92eb8ecdb5b7f568fb3_32162.ko" 
in 8770usr/1700sys/13743real ms.
Copying /tmp/stapyBp3bx/stap_4607b376b916b92eb8ecdb5b7f568fb3_32162.ko 
to /root/.systemtap/cache/46/stap_4607b376b916b92eb8ecdb5b7f568fb3_32162.ko
Copying /tmp/stapyBp3bx/stap_4607b376b916b92eb8ecdb5b7f568fb3_32162.c to 
/root/.systemtap/cache/46/stap_4607b376b916b92eb8ecdb5b7f568fb3_32162.c
Copying /tmp/stapyBp3bx/stapconf_9814d8f6012cead5da3a6b75e3c6bd04_300.h 
to /root/.systemtap/cache/98/stapconf_9814d8f6012cead5da3a6b75e3c6bd04_300.h
ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00)


The dropwatch.stp example and others work fine.


I just upgraded from systemtap 1.1 to 1.2 and also tried the latest 
snapshot.  When using systemtap 1.1 a few days ago the tcp_trace.stp 
example worked fine.

I'm using linux 2.6.34-rc3

Thanks for any help.

Karl

Re: ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00)

[Frank Ch. Eigler]

Karl Hiramoto <karl@hiramoto.org> writes:

> I'm a systemtap newbie.  I get the following error with the
> tcp_trace.stp example and others.
> [...]
> ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00)

> The dropwatch.stp example and others work fine.

Interesting.

> I just upgraded from systemtap 1.1 to 1.2 and also tried the latest
> snapshot.  When using systemtap 1.1 a few days ago the tcp_trace.stp
> example worked fine.

There were indeed some changes in the way the build-id matching is
done.  What is the output of 'readelf -x .notes' on your vmlinux file?
Can you try applying the following patch to .../systemtap/runtime/sym.c
and rerun your test?

- FChE

diff --git a/runtime/sym.c b/runtime/sym.c
index 3c69fb1..e1e6e22 100644
--- a/runtime/sym.c
+++ b/runtime/sym.c
@@ -311,15 +311,15 @@ static int _stp_module_check(void)
                              loc2c-runtime.h were more easily usable,
                              a deref() loop could do it too. */
                             mm_segment_t oldfs = get_fs();
-                            int rc;
+                            int rc1, rc2;
                             unsigned char theory, practice;
 
                             set_fs(KERNEL_DS);
-                            rc = get_user(theory,((unsigned char*) &m->build_id_bits[j]));
-                            rc = get_user(practice,((unsigned char*) (void*) (notes_addr+j)));
+                            rc1 = get_user(theory,((unsigned char*) &m->build_id_bits[j]));
+                            rc2 = get_user(practice,((unsigned char*) (void*) (notes_addr+j)));
                             set_fs(oldfs);
 
-                            if (rc || theory != practice) {
+                            if (rc1 || rc2 || (theory != practice)) {
                                     const char *basename;
                                     basename = strrchr(m->path, '/');
                                     if (basename)
@@ -328,15 +328,15 @@ static int _stp_module_check(void)
                                             basename = m->path;
                                     
 #if LINUX_VERSION_CODE >= KERNEL_VERSION(2,6,27)
-                                    _stp_error ("Build-id mismatch: \"%s\" vs. \"%s\" byte %d (0x%02x vs 0x%02x)\n",
-                                                m->name, basename, j, theory, practice);
+                                    _stp_error ("Build-id mismatch: \"%s\" vs. \"%s\" byte %d (0x%02x vs 0x%02x) rc %d %d\n",
+                                                m->name, basename, j, theory, practice, rc1, rc2);
                                     return 1;
 #else
                                     /* This branch is a surrogate for kernels
                                      * affected by Fedora bug #465873. */
                                     _stp_warn (KERN_WARNING
-                                               "Build-id mismatch: \"%s\" vs. \"%s\" byte %d (0x%02x vs 0x%02x)\n",
-                                               m->name, basename, j, theory, practice);
+                                               "Build-id mismatch: \"%s\" vs. \"%s\" byte %d (0x%02x vs 0x%02x) rc %d %d\n",
+                                               m->name, basename, j, theory, practice, rc1, rc2);
 #endif
                                     break;
                             } /* end mismatch */

Re: ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00)

[Karl Hiramoto]

On 04/07/2010 09:32 PM, Frank Ch. Eigler wrote:
> There were indeed some changes in the way the build-id matching is
> done.  What is the output of 'readelf -x .notes' on your vmlinux file?
> Can you try applying the following patch to .../systemtap/runtime/sym.c
> and rerun your test?
>    
Now it the output error is:

Pass 2: analyzed script: 13 probe(s), 58 function(s), 3 embed(s), 35 
global(s) using 158136virt/64500res/2664shr kb, in 
3300usr/1000sys/5023real ms.
identified max-nested function: _dwarf_tvar_get_cast_38 (1)
identified max-nested function: __ip_sock_saddr (2)
identified max-nested function: _dwarf_tvar_get_cast_36 (3)
function recursion-analysis: max-nesting 3 non-recursive
probe_1979 locks key_list[rw] lastkey[w] snd_cwnd[rw] snd_wnd[rw] 
srtt[rw] state[rw] txq[rw] rxq[rw] rexmit[rw] pmtu[rw] ssthresh[rw] 
tx_timer[r] rcvwnd[rw] length[rw]
probe_1980 elided, duplicates probe_1979
probe_1981 locks key_list[rw] lastkey[w] snd_cwnd[rw] snd_wnd[rw] 
srtt[rw] state[rw] txq[rw] rxq[rw] rexmit[rw] pmtu[rw] ssthresh[rw] 
tx_timer[r] rcvwnd[rw] length[rw]
probe_1982 locks key_list[rw] lastkey[w] snd_cwnd[rw] snd_wnd[rw] 
srtt[rw] state[rw] txq[rw] rxq[rw] rexmit[rw] pmtu[rw] ssthresh[rw] 
tx_timer[rw] rcvwnd[rw] length[rw]
probe_1983 locks key_list[rw] lastkey[w] snd_cwnd[rw] snd_wnd[rw] 
srtt[rw] state[rw] txq[rw] rxq[rw] rexmit[rw] pmtu[rw] ssthresh[rw] 
tx_timer[rw] rcvwnd[rw] length[rw]
probe_1984 locks key_list[rw] lastkey[w] snd_cwnd[rw] snd_wnd[rw] 
srtt[rw] state[rw] txq[rw] rxq[rw] rexmit[rw] pmtu[rw] ssthresh[rw] 
tx_timer[rw] find_timer[rw] rcvwnd[rw] length[rw]
probe_1985 locks key_list[rw] lastkey[w] snd_cwnd[rw] snd_wnd[rw] 
srtt[rw] state[rw] txq[rw] rxq[rw] rexmit[rw] pmtu[rw] ssthresh[rw] 
tx_timer[rw] find_timer[rw] rcvwnd[rw] length[rw]
probe_1986 locks key_list[rw] lastkey[w] find_timer[w]
probe_1987 locks key_list[rw] lastkey[w] snd_cwnd[rw] snd_wnd[rw] 
srtt[rw] state[rw] txq[rw] rxq[rw] rexmit[rw] pmtu[rw] ssthresh[rw] 
tx_timer[rw] find_timer[rw] rcvwnd[rw] length[rw]
probe_1988 locks timeout[rw]
stap_dwarf_probe module[7]
stap_dwarf_probe section[7]
stap_dwarf_probe pp[71]
dump_unwindsyms kernel index=0 base=0xc1000000
Found build-id in kernel, length 20, end at 0xc146d654
Found kernel _stext extra offset 0x10e8
Pass 3: translated to C into 
"/tmp/stapmb77Dh/stap_79d90ae157836611691d7f723aa35ebc_32252.c" using 
157728virt/67072res/5416shr kb, in 820usr/30sys/915real ms.
ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00) 
rc -14 -14
Pass 5: run failed.  Try again with another '--vp 00001' option.



readelf -x .notes /usr/src/linux/vmlinux

Hex dump of section '.notes':
   0xc146d630 04000000 14000000 03000000 474e5500 ............GNU.
   0xc146d640 274c0491 926a1565 cd7728cd aa8aaa84 'L...j.e.w(.....
   0xc146d650 fd38e5a8                            .8..

readelf -v
GNU readelf (GNU Binutils) 2.18


  gcc -v
Using built-in specs.
Target: i686-pc-linux-gnu
Configured with: 
/var/tmp/portage/sys-devel/gcc-4.3.4/work/gcc-4.3.4/configure 
--prefix=/usr --bindir=/usr/i686-pc-linux-gnu/gcc-bin/4.3.4 
--includedir=/usr/lib/gcc/i686-pc-linux-gnu/4.3.4/include 
--datadir=/usr/share/gcc-data/i686-pc-linux-gnu/4.3.4 
--mandir=/usr/share/gcc-data/i686-pc-linux-gnu/4.3.4/man 
--infodir=/usr/share/gcc-data/i686-pc-linux-gnu/4.3.4/info 
--with-gxx-include-dir=/usr/lib/gcc/i686-pc-linux-gnu/4.3.4/include/g++-v4 
--host=i686-pc-linux-gnu --build=i686-pc-linux-gnu --disable-altivec 
--disable-fixed-point --enable-nls --without-included-gettext 
--with-system-zlib --disable-checking --disable-werror 
--enable-secureplt --disable-multilib --enable-libmudflap 
--disable-libssp --enable-libgomp --disable-libgcj --with-arch=i686 
--enable-languages=c,c++,treelang,fortran --enable-shared 
--enable-threads=posix --enable-__cxa_atexit --enable-clocale=gnu 
--with-bugurl=http://bugs.gentoo.org/ --with-pkgversion='Gentoo 4.3.4 
p1.0, pie-10.1.5'
Thread model: posix
gcc version 4.3.4 (Gentoo 4.3.4 p1.0, pie-10.1.5)

--
Karl

Re: ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00)

[Frank Ch. Eigler]

Hi -

karl@hiramoto.org wrote:

> dump_unwindsyms kernel index=0 base=0xc1000000
> Found build-id in kernel, length 20, end at 0xc146d654
> Found kernel _stext extra offset 0x10e8
> [...]
> ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00) rc -14 -14

-14 is -EFAULT.  This should not happen unless our address
calculations have gotten messed up somehow.  Try rerunning stap with
-DDEBUG_TRANS -DDEBUG_SYMBOLS.

> readelf -x .notes /usr/src/linux/vmlinux
> Hex dump of section '.notes':
>   0xc146d630 04000000 14000000 03000000 474e5500 ............GNU.
>   0xc146d640 274c0491 926a1565 cd7728cd aa8aaa84 'L...j.e.w(.....
>   0xc146d650 fd38e5a8                            .8..

This looks fine; does it match `od -t x4 /sys/kernel/notes` ?


- FChE

Re: ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00)

[Karl Hiramoto]

On 04/08/2010 04:55 PM, Frank Ch. Eigler wrote:
> -14 is -EFAULT.  This should not happen unless our address
> calculations have gotten messed up somehow.  Try rerunning stap with
> -DDEBUG_TRANS -DDEBUG_SYMBOLS.
Here are full logs with " stap --vp 9999 -DDEBUG_TRANS -DDEBUG_SYMBOLS"

The working dropwatch:
http://karl.hiramoto.org/temp/stap_dropwatch.txt

The non working tcp_trace
http://karl.hiramoto.org/temp/stap_tcp_trace.txt

there's also some errors like:

if gcc -D__KERNEL__  -I/home/karl/Work/linux-2.6/arch/x86/include -Iinclude  -include include/generated/autoconf.h -Wall -Wundef -Wstrict-prototypes -Wno-trigraphs -fno-strict-aliasing -fno-common -Werror-implicit-function-declaration -Wno-format-security -fno-delete-null-pointer-checks -Os -m32 -msoft-float -mregparm=3 -freg-struct-return -mpreferred-stack-boundary=2 -march=i686 -mtune=core2 -mtune=generic -Wa,-mtune=generic32 -ffreestanding -DCONFIG_AS_CFI=1 -DCONFIG_AS_CFI_SIGNAL_FRAME=1 -pipe -Wno-sign-compare -fno-asynchronous-unwind-tables -mno-sse -mno-mmx -mno-sse2 -mno-3dnow -fno-stack-protector -fno-omit-frame-pointer -fno-optimize-sibling-calls -g -pg -Wdeclaration-after-statement -Wno-pointer-sign -fno-strict-overflow    -DKBUILD_BASENAME=\"stap_d6e88c4e8f2263618d7bbc0d0f11ab92_32276\" -Werror -S -o /dev/null -xc  "/usr/share/systemtap/runtime"/autoconf-grsecurity.c; then echo "#define STAPCONF_GRSECURITY
1"; fi>>  /tmp/stapEyVbEM/stapconf_6415a8d55b7118f55f4e4a8368ac8512_390.h
/usr/share/systemtap/runtime/autoconf-grsecurity.c: In function ‘foo’:
/usr/share/systemtap/runtime/autoconf-grsecurity.c:10: error: ‘struct module’ has no member named ‘init_size_rw’
/usr/share/systemtap/runtime/autoconf-grsecurity.c:10: error: ‘struct module’ has no member named ‘init_size_rx’
/usr/share/systemtap/runtime/autoconf-grsecurity.c:10: error: ‘struct module’ has no member named ‘core_size_rw’
/usr/share/systemtap/runtime/autoconf-grsecurity.c:10: error: ‘struct module’ has no member named ‘core_size_rx’


if gcc -D__KERNEL__  -I/home/karl/Work/linux-2.6/arch/x86/include -Iinclude  -include include/generated/autoconf.h -Wall -Wundef -Wstrict-prototypes -Wno-trigraphs -fno-strict-aliasing -fno-common -Werror-implicit-function-declaration -Wno-format-security -fno-delete-null-pointer-checks -Os -m32 -msoft-float -mregparm=3 -freg-struct-return -mpreferred-stack-boundary=2 -march=i686 -mtune=core2 -mtune=generic -Wa,-mtune=generic32 -ffreestanding -DCONFIG_AS_CFI=1 -DCONFIG_AS_CFI_SIGNAL_FRAME=1 -pipe -Wno-sign-compare -fno-asynchronous-unwind-tables -mno-sse -mno-mmx -mno-sse2 -mno-3dnow -fno-stack-protector -fno-omit-frame-pointer -fno-optimize-sibling-calls -g -pg -Wdeclaration-after-statement -Wno-pointer-sign -fno-strict-overflow    -DKBUILD_BASENAME=\"stap_d6e88c4e8f2263618d7bbc0d0f11ab92_32276\" -Werror -S -o /dev/null -xc  "/usr/share/systemtap/runtime"/autoconf-utrace-regset.c; then echo "#define STAPCONF_UTRACE_R
EGSET 1"; fi>>  /tmp/stapEyVbEM/stapconf_6415a8d55b7118f55f4e4a8368ac8512_390.h
/usr/share/systemtap/runtime/autoconf-utrace-regset.c: In function ‘foobar’:
/usr/share/systemtap/runtime/autoconf-utrace-regset.c:5: error: implicit declaration of function utrace_native_view
cc1: warnings being treated as errors
/usr/share/systemtap/runtime/autoconf-utrace-regset.c:5: error: initialization makes pointer from integer without a cast
/usr/share/systemtap/runtime/autoconf-utrace-regset.c:6: error: dereferencing pointer to incomplete type
/usr/share/systemtap/runtime/autoconf-utrace-regset.c:7: error: dereferencing pointer to incomplete type
/usr/share/systemtap/runtime/autoconf-utrace-regset.c:7: error: dereferencing pointer to incomplete type



> This looks fine; does it match `od -t x4 /sys/kernel/notes` ?
>
>    
They look the same but with the endianness swapped, not sure if thats 
normal.

# readelf -x .notes /usr/src/linux/vmlinux

Hex dump of section '.notes':
0xc14668b0 04000000 14000000 03000000 474e5500 ............GNU.
0xc14668c0 6a9e175e 82c9b226 2211855b 82f64361 j..^...&"..[..Ca
0xc14668d0 4b001d11 K...

# od -t x4 /sys/kernel/notes
0000000 00000004 00000014 00000003 00554e47
0000020 5e179e6a 26b2c982 5b851122 6143f682
0000040 111d004b
0000044


Thanks

--
Karl

Re: ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00)

[Frank Ch. Eigler]

Hi -


> >-14 is -EFAULT.  This should not happen unless our address
> >calculations have gotten messed up somehow.  Try rerunning stap with
> >-DDEBUG_TRANS -DDEBUG_SYMBOLS.

> Here are full logs with " stap --vp 9999 -DDEBUG_TRANS -DDEBUG_SYMBOLS"
> The working dropwatch:
> http://karl.hiramoto.org/temp/stap_dropwatch.txt
> The non working tcp_trace
> http://karl.hiramoto.org/temp/stap_tcp_trace.txt

Thanks.

The difference is that dropwatch uses tracepoints only, and does not
rely on kernel symbol/debug data.  That in turn means that stap does
not emit build-id-checking code.  A better test would be to vary
kernel version and/or systemtap version, but running with the same
script.  (Even a simple one like  probe kernel.function("sys_open"){}
should show the problem.)

I'm building myself a 2.6.34-rc3 kernel to see if something became
broken lately.


> there's also some errors like:
> [...]
> /tmp/stapEyVbEM/stapconf_6415a8d55b7118f55f4e4a8368ac8512_390.h
> /usr/share/systemtap/runtime/autoconf-grsecurity.c: In function foo:
> /usr/share/systemtap/runtime/autoconf-grsecurity.c:10: error: struct 
> module) has no member namedi~init_size_
> [...]

That's OK, runtime/autoconf-* bits are meant to detect kernel
characteristics by compilation success / failures.


- FChE

Re: ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00)

[Karl Hiramoto]

On 04/08/2010 07:06 PM, Frank Ch. Eigler wrote:
> n A better test would be to vary
> kernel version and/or systemtap version, but running with the same
> script.
>    

The tcp_trace.stp works fine with systemtap 1.1 on  my system, but 1.2 
and the newer snapshots fail.

--
Karl

Re: ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00)

[Frank Ch. Eigler]

Hi -

> The tcp_trace.stp works fine with systemtap 1.1 on  my system, but 1.2 
> and the newer snapshots fail.

OK, that's good information.  Next step then is to run stap -k with
both versions, and compare the /tmp/stapXXXX/* files, expecially
stap-symbols.h.  They should be the same, specifically they should
include the same buildid bytes / addresses.  That would leave only
the buildid checking logic as different.  The new code in runtime/sym.c
does this:

      set_fs(KERNEL_DS);
      rc1 = get_user(theory,((unsigned char*) &m->build_id_bits[j]));
      rc2 = get_user(practice,((unsigned char*) (void*) (notes_addr+j)));
      set_fs(oldfs);

in order to fetch two bytes from kernel space (from not entirely
reliable addresses).  The old code just memcmp'd the whole arrays
(leading to crashes in the case of not entirely correct addresses).


- FChE

Re: ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 0 (0x00 vs 0x00)

[Tony Jones]

On Thu, Apr 08, 2010 at 02:30:49PM -0400, Frank Ch. Eigler wrote:
> Hi -
> 
> > The tcp_trace.stp works fine with systemtap 1.1 on  my system, but 1.2 
> > and the newer snapshots fail.
> 
> OK, that's good information.  Next step then is to run stap -k with
> both versions, and compare the /tmp/stapXXXX/* files, expecially
> stap-symbols.h.  They should be the same, specifically they should
> include the same buildid bytes / addresses.  That would leave only
> the buildid checking logic as different.  The new code in runtime/sym.c
> does this:
> 
>       set_fs(KERNEL_DS);
>       rc1 = get_user(theory,((unsigned char*) &m->build_id_bits[j]));
>       rc2 = get_user(practice,((unsigned char*) (void*) (notes_addr+j)));
>       set_fs(oldfs);
> 
> in order to fetch two bytes from kernel space (from not entirely
> reliable addresses).  The old code just memcmp'd the whole arrays
> (leading to crashes in the case of not entirely correct addresses).
> 
> 
> - FChE

Post 1.1 I've been seeing the following on i686 (x86_64 is ok):

ERROR: Build-id mismatch: "kernel" vs. "vmlinux-2.6.34-8-default.debug" byte 0 (0x00 vs 0x00) rc -14 -14
Pass 5: run failed.  Try again with another '--vp 00001' option.

as per irc discussion, following test diff fixed the problem on i686, I've not
tested on any other archs.

Tony


diff --git a/buildrun.cxx b/buildrun.cxx
index 4d4e235..e9cffcb 100644
--- a/buildrun.cxx
+++ b/buildrun.cxx
@@ -183,7 +183,7 @@ compile_pass (systemtap_session& s)
   output_autoconf(s, o, "autoconf-uprobe-get-pc.c", "STAPCONF_UPROBE_GET_PC", NULL);
   output_exportconf(s, o, "cpu_khz", "STAPCONF_CPU_KHZ");
 
-#if 0
+#if 1
   /* NB: For now, the performance hit of probe_kernel_read/write (vs. our
    * homegrown safe-access functions) is deemed undesireable, so we'll skip
    * this autoconf. */
diff --git a/runtime/sym.c b/runtime/sym.c
index 563d4f7..f0f9fb0 100644
--- a/runtime/sym.c
+++ b/runtime/sym.c
@@ -17,6 +17,10 @@
 #include "task_finder_vma.c"
 #include <asm/uaccess.h>
 
+#ifdef STAPCONF_PROBE_KERNEL
+#include <linux/uaccess.h>
+#endif
+
 /* Callback that needs to be registered (in
    session.unwindsyms_modules) for every user task path for which we
    might need symbols or unwind info. */
@@ -346,10 +350,15 @@ static int _stp_module_check(void)
                             int rc1, rc2;
                             unsigned char theory, practice;
 
+#ifdef STAPCONF_PROBE_KERNEL
+			    rc1=probe_kernel_read(&theory, (void*)&m->build_id_bits[j], 1);
+			    rc2=probe_kernel_read(&practice, (void*)(notes_addr+j), 1);
+#else
                             set_fs(KERNEL_DS);
                             rc1 = get_user(theory,((unsigned char*) &m->build_id_bits[j]));
                             rc2 = get_user(practice,((unsigned char*) (void*) (notes_addr+j)));
                             set_fs(oldfs);
+#endif
 
                             if (rc1 || rc2 || (theory != practice)) {
                                     const char *basename;