11 Jan
2005
11 Jan
'05
9:33 a.m.
In anticipation of doing some work on performance issues, I've been
experimenting with our kernel profiler the last few days. For those who
don't know, you can activate the profiler by including the /PROFILE option
on the command line. On each timer interrupt the current EIP will be saved,
after 30 sec a background task will convert the saved EIPs to function
name/file name, count how often each function name occurs and write the
results to a file %system_root%\profiler.log. There are 100 timer ticks per
second, a 30 sec measuring interval will therefore generate 3000 EIPs.
This works very nice, but I'm running into one problem on my 300MHz test
machine: conversion of the EIPs to function name by the background thread
takes about 60 sec. Almost all of that time is spent looking up the correct
.stabs entry from the info in the .sym file. This is done using a linear
search. Since there can be 100000 .stabs entries in a .sym file, going
through these for each of the 3000 measurements can mean 300000000 compares.
Even worse, two passes are made through the .stabs list for each
measurement, one to find the function name and one to find the file name. No
wonder this takes 60 sec.
So, we need to improve the search. I've done some simulations, and when I
use a binary search instead of a linear search, the performance is
dramatically better. Time required to convert all measurements drops from 60
sec to 0.06 sec, a 1000 fold improvement.
To be able to use a binary search, the information in the .sym file needs to
be sorted and uniform (each element contains the same type of data) which it
currently isn't. We have .stabs entries defining a function (N_FUN), source
line (N_SLINE) and source file (N_SO). Currently, we only use the .sym files
to convert an address to function name/file name/source line, not the other
way around (no function name to address for example). I'd like to drop using
the .stab format in the .sym files and change to the following format:
+----------+
|header |
+----------+
|symentries|
+----------+
|strings |
+----------+
The header would just contain the start location and number of symentries
plus start location and total size of the strings. Each symentry would have
the following info:
typedef struct tagSYM_ENTRY {
ULONG_PTR Address;
ULONG FunctionOffset;
ULONG FileOffset;
ULONG SourceLine;
} SYM_ENTRY, *PSYM_ENTRY;
where Address is an address relative to the beginning of the module,
FunctionOffset and FileOffset are offsets from the beginning of the strings
section and SourceLine contains the source line number. The symentries are
sorted by Address (done by rsym). Each Address would only appear once, and
information would be made as complete as possible (e.g. when creating the
symentries from the .stabs in the .nostrip.exe file each FunctionOffset
would be set to point to the function name from the most recently
encountered N_FUN .stab). This will allow us to retrieve all 3 pieces of
information (function name, file name and source line) by doing just a
single binary search.
Comments, thoughts, objections?
Gé van Geldorp.
11 Jan
11 Jan
10:42 a.m.
-----Original Message-----
From: ros-dev-bounces(a)reactos.com
[mailto:ros-dev-bounces@reactos.com] On Behalf Of Ge van Geldorp
Sent: 11. januar 2005 10:34
To: ros-dev(a)reactos.com
Subject: [ros-dev] Proposal to change .sym files
Comments, thoughts, objections?
I like this. If you could put the .sym parsing functions in their
own static library in the process (for use in reporterror.exe) then
that would be even more great.
Casper
1:36 p.m.
Ge van Geldorp wrote:
In anticipation of doing some work on performance
issues, I've been
experimenting with our kernel profiler the last few days. For those who
don't know, you can activate the profiler by including the /PROFILE option
on the command line. On each timer interrupt the current EIP will be saved,
after 30 sec a background task will convert the saved EIPs to function
name/file name, count how often each function name occurs and write the
results to a file %system_root%\profiler.log. There are 100 timer ticks per
second, a 30 sec measuring interval will therefore generate 3000 EIPs.
This works very nice, but I'm running into one problem on my 300MHz test
machine: conversion of the EIPs to function name by the background thread
takes about 60 sec. Almost all of that time is spent looking up the correct
.stabs entry from the info in the .sym file. This is done using a linear
search. Since there can be 100000 .stabs entries in a .sym file, going
through these for each of the 3000 measurements can mean 300000000 compares.
Even worse, two passes are made through the .stabs list for each
measurement, one to find the function name and one to find the file name. No
wonder this takes 60 sec.
So, we need to improve the search. I've done some simulations, and when I
use a binary search instead of a linear search, the performance is
dramatically better. Time required to convert all measurements drops from 60
sec to 0.06 sec, a 1000 fold improvement.
To be able to use a binary search, the information in the .sym file needs to
be sorted and uniform (each element contains the same type of data) which it
currently isn't. We have .stabs entries defining a function (N_FUN), source
line (N_SLINE) and source file (N_SO). Currently, we only use the .sym files
to convert an address to function name/file name/source line, not the other
way around (no function name to address for example). I'd like to drop using
the .stab format in the .sym files and change to the following format:
+----------+
|header |
+----------+
|symentries|
+----------+
|strings |
+----------+
The header would just contain the start location and number of symentries
plus start location and total size of the strings. Each symentry would have
the following info:
typedef struct tagSYM_ENTRY {
ULONG_PTR Address;
ULONG FunctionOffset;
ULONG FileOffset;
ULONG SourceLine;
} SYM_ENTRY, *PSYM_ENTRY;
where Address is an address relative to the beginning of the module,
FunctionOffset and FileOffset are offsets from the beginning of the strings
section and SourceLine contains the source line number. The symentries are
sorted by Address (done by rsym). Each Address would only appear once, and
information would be made as complete as possible (e.g. when creating the
symentries from the .stabs in the .nostrip.exe file each FunctionOffset
would be set to point to the function name from the most recently
encountered N_FUN .stab). This will allow us to retrieve all 3 pieces of
information (function name, file name and source line) by doing just a
single binary search.
Comments, thoughts, objections?
Gé van Geldorp.
The only reason I didn't do something like this was because I was
worried about the effect on build-time, which at the moment is already
horrendous. If this sorting can be done quickly ( i.e. have minimal
effect on build time), then I think it's a great idea.
Also, how much larger do you anticipate the sym files getting, and do we
have the kmode address space available to devote to this increase in
size with room to spare?
I apologize if some of these questions are stupid ;)
2:19 p.m.
From: Royce Mitchell III
The only reason I didn't do something like this was because I was
worried about the effect on build-time, which at the moment
is already horrendous. If this sorting can be done quickly
( i.e. have minimal effect on build time), then I think it's
a great idea.
My gut feeling is that it won't impact build time very much, but I won't
know for sure until I've coded the thing.
Also, how much larger do you anticipate the sym files
getting, and do we have the kmode address space available
to devote to this increase in size with room to spare?
A STAB_ENTRY as currently used is 12 bytes, my proposed SYM_ENTRY is 16
bytes. There can be multiple STAB_ENTRYs for a single address, while there
will be only 1 SYM_ENTRY. Strings are handled the same by both formats, they
are stored in a string table. All in all, I'd guess the new sym files to be
10% larger than the old ones. Seems a reasonable price to pay.
I apologize if some of these questions are stupid ;)
No such thing as a stupid question. Perhaps asking on IRC whether accept()
works is annoying, but it's still not stupid ;)
Gé van Geldorp.
3:43 p.m.
Ge van Geldorp schrieb:
This works very nice, but I'm running into one
problem on my 300MHz test
machine: conversion of the EIPs to function name by the background thread
takes about 60 sec. Almost all of that time is spent looking up the correct
.stabs entry from the info in the .sym file. This is done using a linear
search. Since there can be 100000 .stabs entries in a .sym file, going
through these for each of the 3000 measurements can mean 300000000 compares.
Even worse, two passes are made through the .stabs list for each
measurement, one to find the function name and one to find the file name. No
wonder this takes 60 sec.
Sometimes ago there has exist a profiling function which has used the
hash table functions from ex\hashtable.c. The problem is that the hash
table functions uses the splay tree functions which are broken. In my
local sources I had replaced the splay tree by a simple double linked
list. I've never see such speed problems. This was at the begining of
2003. I had used the profiling for compiling ros on ros.
I would like it if we can add the sym files as a no-load section to each
binary. This protects from using wrong symbol files and does help for
some binaries like packet.sys and packet.dll.
- Hartmut
4:33 p.m.
On Tue, 11 Jan 2005 16:43:17 +0100
Hartmut Birr <hartmut.birr(a)gmx.de> wrote:
I would like it if we can add the sym files as a
no-load section to each
binary. This protects from using wrong symbol files and does help for
some binaries like packet.sys and packet.dll.
- Hartmut
I agree that i like symbols better in their binaries than out.
--
Here's a simple experiment. Stand on a train track between two locomotives
which are pushing on you with equal force in opposite directions. You will
exhibit no net motion. None the less, you may soon begin to notice that
something important is happening.
-- Robert Stirniman
8:44 p.m.
From: art yerkes
On Tue, 11 Jan 2005 16:43:17 +0100
Hartmut Birr <hartmut.birr(a)gmx.de> wrote:
Hmm, maybe we should just use the *.nostrip.* stuff then and possibly
convert at runtime? It doesn't make much sense to me to first create a
stripped version and then add back the symbols.
Ge van Geldorp.
I would like it if we can add the sym files as a
no-load
section to each binary. This protects from using wrong
symbol files and does help for some binaries like
packet.sys and packet.dll.
I agree that i like symbols better in their binaries than out. 
12 Jan
12 Jan
6:30 p.m.
On Tuesday 11 January 2005 21:44, Ge van Geldorp wrote:
Converting at runtime could be slow, but we definitly have to convert them
into a format which we can save as one large block in memory (and not
thousands of small blocks) and easily parse at runtime.
What about using GNU debuglinks? It works like this:
You create the binary with debug info. Then you copy the debug info from the
binary into a debug/symbol file. The next step is to strip the debug info
from the binary and at the same time add a debug link to the debug file.
The debug link is a section in the binary (which can be added with objdump
when stripping debug info from the binary) called .gnu_debuglink. It must
contain the filename of the debug file (zero-terminated) and (aligned to 4
bytes) the CRC of the debug file (which makes sure that correct symbols will
be used with the binary)
GNU binutils support it so it's easy to create the symbol files and add the
debug links to the binaries.
- blight
From: art
yerkes
On Tue, 11 Jan 2005 16:43:17 +0100
Hartmut Birr <hartmut.birr(a)gmx.de> wrote:
Hmm, maybe we should just use the *.nostrip.* stuff then and possibly
convert at runtime? It doesn't make much sense to me to first create a
stripped version and then add back the symbols.
Ge van Geldorp. I would like it if we can add the sym files as a
no-load
section to each binary. This protects from using wrong
symbol files and does help for some binaries like
packet.sys and packet.dll.
I agree that i like symbols better in their binaries than out.
13 Jan
13 Jan
8:42 p.m.
Anich Gregor schrieb:
Converting at runtime could be slow, but we definitly
have to convert them
into a format which we can save as one large block in memory (and not
thousands of small blocks) and easily parse at runtime.
What about using GNU debuglinks? It works like this:
You create the binary with debug info. Then you copy the debug info from the
binary into a debug/symbol file. The next step is to strip the debug info
from the binary and at the same time add a debug link to the debug file.
The debug link is a section in the binary (which can be added with objdump
when stripping debug info from the binary) called .gnu_debuglink. It must
contain the filename of the debug file (zero-terminated) and (aligned to 4
bytes) the CRC of the debug file (which makes sure that correct symbols will
be used with the binary)
GNU binutils support it so it's easy to create the symbol files and add the
debug links to the binaries.
- blight
I'm not sure if you mean objcopy instead of objdump. Objcopy for pe
images isn't usable, because it changes the file and section
allignments. I think that we need a tool which creates our new debug
section as coff object file from the *.nostriped.* and that we need our
own linker scripts which adds the section at the correct position within
the image. This needs also a little change in freeldr, because the
symbol section must be located after the bss section in ntoskrnl.
- Hartmut
9:33 p.m.
From: Hartmut Birr
I'm not sure if you mean objcopy instead of objdump. Objcopy
for pe images isn't usable, because it changes the file and
section allignments. I think that we need a tool which creates
our new debug section as coff object file from the *.nostriped.*
and that we need our own linker scripts which adds the section
at the correct position within the image. This needs also a
little change in freeldr, because the symbol section must be
located after the bss section in ntoskrnl.
This is getting a bit over my head, I'm no hero with COFF, linker scripts
and binutils in general. If I code the generation of the basic symbol file,
would someone else be able (and willing) to change it to a COFF object file
and do the linker magic?
Gé van Geldorp.
14 Jan
14 Jan
5:11 p.m.
Ge van Geldorp schrieb:
Hi,
the coff format is very simple if no relocation and debug infos are
needed. A good starting point is http://www.delorie.com/djgpp/doc/coff.
I've add a little diff. Rsym puts each symbol info in a file named
symbol.coff. Ntoskrnl is build with the symbol section. While inspecting
ntoskrnl.exe, I've found some other bugs. Ntoskrnl.exe contains always a
.stab and a .stabstr section. There exist relocation entries for the
.stab and .stabstr section. There exist relocation entries for addresses
after the end of the image.
- Hartmut
From: Hartmut
Birr
I'm not sure if you mean objcopy instead of objdump. Objcopy
for pe images isn't usable, because it changes the file and
section allignments. I think that we need a tool which creates
our new debug section as coff object file from the *.nostriped.*
and that we need our own linker scripts which adds the section
at the correct position within the image. This needs also a
little change in freeldr, because the symbol section must be
located after the bss section in ntoskrnl.
This is getting a bit over my head, I'm no hero with COFF, linker scripts
and binutils in general. If I code the generation of the basic symbol file,
would someone else be able (and willing) to change it to a COFF object file
and do the linker magic?
Gé van Geldorp.
_______________________________________________
Ros-dev mailing list
Ros-dev(a)reactos.com
http://reactos.com:8080/mailman/listinfo/ros-dev
26 Jan
26 Jan
7:15 p.m.
From: Hartmut Birr
the coff format is very simple if no relocation and debug infos are
needed. A good starting point is http://www.delorie.com/djgpp/doc/coff.
I've add a little diff. Rsym puts each symbol info in a file named
symbol.coff. Ntoskrnl is build with the symbol section.
Thanks, your code works great for ntoskrnl.exe. However, I'm having trouble
getting it right in other executables. If I set scnhdr.s_flags to "CONTENTS,
ALLOC, LOAD, DATA" (0xc0000040, like .rsrc) symbol.coff is properly linked
into the final executable, but it will take up space in the loaded image. If
I set scnhdr.s_flags to "CONTENTS, READONLY, DEBUGGING, NEVER_LOAD, EXCLUDE"
(0x42000802, like .stab) then the final executable does not include the
.rossym section.
While inspecting ntoskrnl.exe, I've found some
other bugs.
Ntoskrnl.exe contains always a .stab and a .stabstr section.
There exist relocation entries for the .stab and .stabstr
section. There exist relocation entries for addresses
after the end of the image.
Yes, I noticed that too. There's another problem: at the moment, we do 2
separate links, one to get driver.nostrip.sys, and then another one to get
driver.sys. We use the symbolic information from driver.nostrip.sys but
execute driver.sys. Unfortunately, it seems the code in driver.sys and
driver.nostrip.sys can differ in small but subtle ways. This seems to happen
when static libraries are used, like in tcpip.sys. Since this makes the
symbolic info not match the executable code, the symbolic info is useless.
So, I'm thinking about changing rsym to take driver.nostrip.sys as input and
produce a driver.sys as output, by stripping the .stab and .stabstr
sections, removing no longer needed relocation entries and removing symbolic
information. While it's at it, it can add the .rossym section too. It should
speed up the build a little bit too, since the second link is replace by
some chopping.
Gé van Geldorp.
27 Jan
27 Jan
6:46 p.m.
Ge van Geldorp schrieb:
However, I'm having trouble
getting it right in other executables. If I set scnhdr.s_flags to "CONTENTS,
ALLOC, LOAD, DATA" (0xc0000040, like .rsrc) symbol.coff is properly linked
into the final executable, but it will take up space in the loaded image. If
I set scnhdr.s_flags to "CONTENTS, READONLY, DEBUGGING, NEVER_LOAD, EXCLUDE"
(0x42000802, like .stab) then the final executable does not include the
.rossym section.
Hi,
have you modified the linker script files from gcc? You must add the
section definition like the changes in ntoskrnl.lnk.
- Hartmut
11 Jan
11 Jan
8:39 p.m.
From: Hartmut Birr
Sometimes ago there has exist a profiling function which has
used the hash table functions from ex\hashtable.c. The problem
is that the hash table functions uses the splay tree functions
which are broken. In my local sources I had replaced the splay
tree by a simple double linked list. I've never see such speed
problems. This was at the begining of 2003. I had used the
profiling for compiling ros on ros.
Yes, sounds like the same profiling stuff I'm using. I already talked to
Casper (original author of the hashtable stuff) about the splay tree.
Note that my profiling experiment is sort of a worst-case scenario. I'm
using a 300 MHz machine which is not exactly roaring with power. I have a
foreground thread running the functions I want to profile, which is
completely CPU bound. So basically the foreground and profile-conversion
thread each get 50% of the CPU. Timing was done by calling
KeQueryTickCount() at beginning and end of the conversion and printing the
difference.
Compiling ros on ros might be a little different, as that might not be CPU
bound. Throw in a faster CPU and the conversion might go a lot faster.
Gé van Geldorp.
2 Feb
2 Feb
11:26 p.m.
(Original message here:
http://reactos.com:8080/archives/public/ros-dev/2005-January/001457.html too
long to quote)
It seems most people liked the idea of getting rid of the .sym files and
incorporate the symbolic information into the PE files. So, that's what
happens now.
rsym will now take a file.nostrip.ext, create the ReactOS symbolic info,
strip unneeded sections (.stab and .stabstr), strip COFF symbols, fixup the
relocation entries, add the ReactOS symbolic info as a .rossym section and
write the output to file.ext. The .sym files are gone. Since this gets rid
of the second link sequence we did before to obtain file.ext, the build is
even a little bit faster now.
It's a bigger change than I expected when I started on it. I've done a lot
of testing in the last few days, but it is entirely possible that I missed
something. If so, let me know and I'll try to fix it asap.
You can delete any files in \reactos\symbols (and remove that directory). A
"make clean" is in order after "svn up".
Gé van Geldorp.
3 Feb
3 Feb
12:12 a.m.
Ge van Geldorp wrote:
(Original message here:
http://reactos.com:8080/archives/public/ros-dev/2005-January/001457.html too
long to quote)
It seems most people liked the idea of getting rid of the .sym files and
incorporate the symbolic information into the PE files. So, that's what
happens now.
Does addr2line still work, or can you provide one for us?
12:24 a.m.
From: Royce Mitchell III
Does addr2line still work, or can you provide one for us?
Yes, addr2line still works, it uses file.nostrip.ext which is unchanged. The
changes are in file.ext. It shouldn't be to hard to create an alternative
tool but there doesn't seem too much point in that.
Gé van Geldorp.
12:46 a.m.
Ge van Geldorp wrote:
Sounds very nice! :-)
From: Royce
Mitchell III
Does addr2line still work, or can you provide one for us?
Yes, addr2line still works, it uses file.nostrip.ext which is unchanged. The
changes are in file.ext. It shouldn't be to hard to create an alternative
tool but there doesn't seem too much point in that.
Gé van Geldorp.
1:04 a.m.
Ge van Geldorp wrote:
Yes, addr2line still works, it uses file.nostrip.ext
which is unchanged. The
changes are in file.ext. It shouldn't be to hard to create an alternative
tool but there doesn't seem too much point in that.
It's my understanding that using addr2line against the nostrip file can
be off sometimes, because of subtle differences between the two files.
Also, there will be times where there are no nostrip files, and we may
have to figure out what's going on from the files the user is using.
8:24 a.m.
From: Royce Mitchell III
It's my understanding that using addr2line against the
nostrip file can be off sometimes, because of subtle
differences between the two files.
I think this problem is solved now too. It was caused by the two links we
used to do, one to get file.nostrip.ext and then another one to get
file.ext. Especially when static libs were involved the second link might
produce a slightly different binary than the first.
The second link is gone now. The code and data is copied unchanged from
file.nostrip.ext to file.ext.
Also, there will be times where there are no nostrip
files,
and we may have to figure out what's going on from the files
the user is using.
If symbolic info was present in file.nostrip.ext (i.e. it was compiled with
-g, which at present implies DBG := 1), then it will also be present in
file.ext. So, the backtrace on e.g. BSODs should print the function
name/source file/source line in addition to the address. Which means we
won't have to use addr2line very often. If there was no symbolic info in
file.nostrip.ext, addr2line wouldn't be of help anyway.
But as I said, creating a util like addr2line for the final file.ext is a
piece of cake, it's just stringing together some calls to the rossym lib.
I'll create something this week.
Which brings me to my last point: I'd like to enable -g (creation of
symbolic info by the toolchain) for all builds, both DBG := 0 and DBG := 1.
The only downside I see is it will take more diskspace to build ReactOS
(currently 725 MB without symbolic info, 2477 MB with) and the final iso
will be slightly larger (13 MB instead of 10MB). Personally I think this is
outweighed by the possibility to have meaningful backtraces. Any objections?
Gé van Geldorp.
12:37 p.m.
Which brings me to my last point: I'd like to
enable -g
(creation of symbolic info by the toolchain) for all builds,
both DBG := 0 and DBG := 1.
The only downside I see is it will take more diskspace to
build ReactOS (currently 725 MB without symbolic info, 2477
MB with) and the final iso will be slightly larger (13 MB
instead of 10MB). Personally I think this is outweighed by
the possibility to have meaningful backtraces. Any objections?
Gé van Geldorp.
Please do. I was going to propose this eventually to have
meaningful error reports for releases. It's a step in the
right direction towards removing the DBG and KDBG
configurations to minimize build errors.
Casper
7170
days inactive
7193
days old
20 comments
7 participants
participants (7)
-
Anich Gregor -
art yerkes -
Casper Hornstrup -
Ge van Geldorp -
Gregor Anich
-
Hartmut Birr -
Royce Mitchell III