On Fri, 21 May 2004, Colin Walters wrote:

On Fri, 2004-05-21 at 07:30, Yusuf Goolamabbas wrote:

...

Hi, I installed Fedora Core 2 on an Athlon 750 with 512MB ram with an Nvidia Vanta II pci video card.

After a fresh boot, I timed the following a) startup of Mozilla from the panel till Release notes was rendered b) startup of gnome-terminal from Fedora Menu->System Tools->Terminal till bash prompt

The timings for a) and b) on 'cold-start' were 10 and 13 seconds respectively. On a 'warm cache' (ie) start Mozilla/shutdown/start again the timings were 3 and 11 seconds respectively.

My expecation is that gnome-terminal is simpler/smaller than Mozilla and as such should startup much faster

My suspicion is that you have something crazy in your shell init files (e.g. ~/.bashrc).

...or there's something wrong with DNS - all Gnome (and KDE for that matter) applications take AGES to start if DNS is failing.

- Panu -

On Fri, 2004-05-21 at 12:22, Troy Dawson wrote:

This was discussed earlier in the thread "Performance tuning the Fedora Desktop". I think Warren had the real explanation, though I'm certain there could be others.

---

In FC2 things have changed for the worse for gnome-terminal performance, where it has become far worse than both konsole and xterm. A GNOME developer explained to me that was the trade-off necessary in making gnome-terminal able to display unicode characters with pango.

Yeah but most of this performance hit comes from displaying large amounts of text, not just starting up and displaying your shell prompt.

On Fri, May 21, 2004 at 07:14:42PM +0300, Panu Matilainen wrote:

On Fri, 21 May 2004, Colin Walters wrote:

...

My suspicion is that you have something crazy in your shell init files (e.g. ~/.bashrc).

...or there's something wrong with DNS - all Gnome (and KDE for that matter) applications take AGES to start if DNS is failing.

Forgot to mention that I did the test immediately after a fresh install so if there is something crazy in the shell init files, it wasn't added by me

DNS works since I can browse the web using Mozilla

During install, I enabled the firewall and allowed ssh in

Regards, /yg

Yusuf Goolamabbas wrote:

On Fri, May 21, 2004 at 07:14:42PM +0300, Panu Matilainen wrote:

...

On Fri, 21 May 2004, Colin Walters wrote:

...

My suspicion is that you have something crazy in your shell init files (e.g. ~/.bashrc).

...or there's something wrong with DNS - all Gnome (and KDE for that matter) applications take AGES to start if DNS is failing.

Forgot to mention that I did the test immediately after a fresh install so if there is something crazy in the shell init files, it wasn't added by me

DNS works since I can browse the web using Mozilla

During install, I enabled the firewall and allowed ssh in

Regards, /yg

I am working on tools and techniques to better measure the performance of desktop applications with the goal of improving performance of desktop applications. xterm would certainly be considered in the desktop. Could you do the fill out the following information and post the results of these simple experiments?

These are still pretty rough procedures, but it will give us some ideas where to look.

What is the hardware configuration of the system:

Processor (output of /proc/cpuinfo): Memory: Harddisk drive: Video card:

What is the software configuration of the system:

kernel being used (uname -r): rpm versions of packages (rpm -qf `which xterm`):

In each case you will need to exit the newly started xterm once it has started.

What is the output of:

/usr/bin/time xterm

What is the output of (note that the output is going to be split between the current xterm and the new xterm:

LD_DEBUG=statistics xterm

Also get a memory map of the xterm:

xterm & # will print out pid of background process. use the number below cat /proc/2201/maps > /tmp/xterm_maps

As root run oprofile to find out which executables and libraries are being used:

opcontrol --setup --vmlinux=/boot/vmlinux-`uname -r` --separate=library opcontrol --reset; opcontrol --start; xterm; opcontrol --shutdown opreport

If there is a complaint about opcontrol not being able to find the kernel image, replace "--vmlinux=/boot/vmlinux-`uname -r`" with "--no-vmlinux".

-Will

Jason Tackaberry wrote:

On Mon, 2004-05-24 at 11:36 -0400, Will Cohen wrote:

...

/usr/bin/time xterm

I don't think this is especially meaningful. If you just want to test the time it takes to load, maybe you want something instead like: time xterm -e ''

Cheers, Jason.

I wanted to see the number of major and minor page faults. Using "time" uses the shell's builtin time which doesn't return that information. Need to have the explicit path in there to avoid using the shell's builtin.

-Will

Jason Tackaberry wrote:

On Tue, 2004-05-25 at 09:16 -0400, Will Cohen wrote:

...

I wanted to see the number of major and minor page faults. Using "time" uses the shell's builtin time which doesn't return that information. Need to have the explicit path in there to avoid using the shell's builtin.

It's funny how you can use *nix for years and years and still pick up little bits like that one, which seem like conventional wisdom.

It's also funny how you can use *nix for years and years, and think you know what you're talking about enough to second guess someone @redhat.com, and then promptly get put in your place. :)

Funny, I learned about passing xterm a command to execute from your email. :)

Sheepishly, Jason.

Seriously, your email was fine. I am sure there will be things that people will need to correct me on, and I did learn something from the email.

Remember the our goal is to improve the performance of the Linux Desktop, not to be correct every single time.

-Will

PS I learned today that gnome actually uses gnome-terminal rather than xterm.

Jason Tackaberry wrote:

On Tue, 2004-05-25 at 16:31 -0400, Will Cohen wrote:

...

Funny, I learned about passing xterm a command to execute from your email. :)

Well that's good to hear. :) The -e switch works with gnome-terminal too, incidentally.

...

Remember the our goal is to improve the performance of the Linux Desktop, not to be correct every single time.

True, being correct every single time doesn't hurt either. :)

It doesn't hurt to be correct. However, I knew some people that got into a wierd mindset with a perfect 4.0 (out of 4.0) grade point average. The 4.0 grade point became the object rather than learning, they had to avoid making mistakes and hurting the 4.0.

...

PS I learned today that gnome actually uses gnome-terminal rather than xterm.

It does, and it definitely could stand some performance improvements. I don't think it's _vastly_ slower than xterm (once it's started), but it does often get in the way.

I think it was Warren who mentioned that he has to minimize gnome-terminal when he's doing a noisy compile otherwise it significantly slows down. That's certainly true for me too (although I just toggle to another tab), but I'm not sure if the real problem is with gnome-terminal, pango, or the underlying font system -- or perhaps at layers even lower than that, like really bad or non-existent Render support in the video driver.

Cheers, Jason.

This morning I played around with some profiling of gnome-terminal. I got a freely available text file from project Gutenberg.net, http://www.gutenberg.net/etext02/jarg422.txt.

I wrote a cruddy little script call cattest to start up oprofile and cat the file, then shutdown oprofile. I ran this on the console of a 2.4GHz p4 machine with 512 MB of memory. The script is attached to this email. It requires an SMP kernel and needs to be run as root.

After running the little script and installing the debuginfo rpms I was able to get some profiles. It looks like this particular machine has a reasonable video card (NVIDIA Quadro 4). Most of the are not for drawing stuff on the screen.

One drawback is rpm with /usr/X11R6/bin/Xorg does not have an associated debuginfo rpm. I assume this is where the redendering happens and where people see the performance hit in gnome-terminal.

The first opreport shows the overall view of which applications had samples and the shared libraries associated with them. The second opreport lists the function-by-function breakdown. Why so much 25% of the time in memchr and real_tolower?

-Will

$ opreport --long-filenames|more CPU: P4 / Xeon, speed 2387.54 MHz (estimated) Counted GLOBAL_POWER_EVENTS events (time during which processor is not stopped) with a unit mask of 0x01 (mandatory) count 100000 GLOBAL_POWER_E...| samples| %| ------------------ 109105 77.3520 /usr/bin/gnome-terminal GLOBAL_POWER_E...| samples| %| ------------------ 34940 32.0242 /lib/tls/libc-2.3.3.so 34762 31.8611 /usr/lib/libvte.so.4.1.1 23412 21.4582 /usr/lib/libglib-2.0.so.0.400.0 4527 4.1492 /usr/X11R6/lib/libXft.so.2.1.2 3126 2.8651 /lib/tls/libpthread-0.61.so 2843 2.6057 /usr/lib/libgobject-2.0.so.0.400.0 2419 2.2171 /usr/lib/libgdk-x11-2.0.so.0.400.0 1090 0.9990 /usr/lib/libgtk-x11-2.0.so.0.400.0 696 0.6379 /usr/X11R6/lib/libX11.so.6.2 549 0.5032 /usr/lib/libfreetype.so.6.3.5 298 0.2731 /usr/lib/gtk-2.0/2.4.0/engines/libbluecurve.so 258 0.2365 /usr/lib/libgthread-2.0.so.0.400.0 143 0.1311 /usr/X11R6/lib/libXrender.so.1.2.2 29 0.0266 /usr/bin/gnome-terminal 7 0.0064 /usr/lib/libfontconfig.so.1.0.4 6 0.0055 /usr/lib/libORBit-2.so.0.0.0 15215 10.7870 /usr/X11R6/bin/Xorg GLOBAL_POWER_E...| samples| %| ------------------ 12259 80.5718 /usr/X11R6/bin/Xorg 2956 19.4282 /lib/tls/libc-2.3.3.so 14393 10.2042 /no-vmlinux

$ opreport image:/usr/bin/gnome-terminal -l --long-filenames|more CPU: P4 / Xeon, speed 2387.54 MHz (estimated) Counted GLOBAL_POWER_EVENTS events (time during which processor is not stopped) with a unit mask of 0x01 (mandatory) count 100000 samples % image name symbol name 16863 15.4558 /lib/tls/libc-2.3.3.so __GI_memchr 12146 11.1324 /usr/lib/libglib-2.0.so.0.400.0 real_tolower 7696 7.0538 /lib/tls/libc-2.3.3.so __GI_memcpy 5693 5.2179 /usr/lib/libvte.so.4.1.1 _vte_iso2022_process 5571 5.1061 /usr/lib/libvte.so.4.1.1 vte_terminal_send 4893 4.4847 /lib/tls/libc-2.3.3.so __GI_memset 3166 2.9018 /usr/lib/libvte.so.4.1.1 vte_sequence_handler_set_title_internal 2547 2.3344 /usr/lib/libglib-2.0.so.0.400.0 g_async_queue_length 2449 2.2446 /usr/lib/libglib-2.0.so.0.400.0 g_async_queue_push_unlocked 2394 2.1942 /usr/lib/libvte.so.4.1.1 vte_terminal_feed_child 2263 2.0741 /usr/lib/libvte.so.4.1.1 _vte_ring_insert_preserve 2152 1.9724 /usr/X11R6/lib/libXft.so.2.1.2 XftGlyphFontSpecRender 2127 1.9495 /usr/lib/libvte.so.4.1.1 __do_global_ctors_aux 1812 1.6608 /usr/lib/libvte.so.4.1.1 vte_invalidate_all 1718 1.5746 /lib/tls/libc-2.3.3.so _int_malloc 1522 1.3950 /usr/lib/libglib-2.0.so.0.400.0 g_unichar_xdigit_value 1470 1.3473 /usr/lib/libvte.so.4.1.1 vte_terminal_key_press 1305 1.1961 /lib/tls/libpthread-0.61.so __pthread_mutex_unlock_usercnt 1263 1.1576 /lib/tls/libpthread-0.61.so __pthread_mutex_lock_internal

#! /bin/bash # # Simple test to gather data on where gnome-terminal spends time # This is compilicated by the terminal server model of gnome-terminal. # Using oprofile to get an overall view of what is happening on the system # This is only going to work with kernel that have oprofile support # (Red Hat SMP kernels)

OPCONTROL=/usr/bin/opcontrol RESULTS_FILE=cattime

$OPCONTROL --deinit $OPCONTROL --reset $OPCONTROL --setup --no-vmlinux --separate=library $OPCONTROL --start /usr/bin/time -o $RESULTS_FILE /bin/cat /home/wcohen/jarg422.txt $OPCONTROL --dump $OPCONTROL --shutdown

#Need to do analysis after running the test.

On Thu, 2004-05-27 at 09:52, Soeren Sandmann Pedersen wrote:

On Tue, 2004-05-25 at 23:31, Will Cohen wrote:

...

After running the little script and installing the debuginfo rpms I was able to get some profiles. It looks like this particular machine has a reasonable video card (NVIDIA Quadro 4). Most of the are not for drawing stuff on the screen.

One drawback is rpm with /usr/X11R6/bin/Xorg does not have an associated debuginfo rpm. I assume this is where the redendering happens and where people see the performance hit in gnome-terminal.

The first opreport shows the overall view of which applications had samples and the shared libraries associated with them. The second opreport lists the function-by-function breakdown. Why so much 25% of the time in memchr and real_tolower?

The memchr() hit comes from this function:

static char * _vte_iso2022_find_nextctl(const char *p, size_t length) { char *ret; if (length == 0) { return NULL; } ret = memchr(p, '\033', length); ret = _vte_iso2022_better(ret, memchr(p, '\n', length)); ret = _vte_iso2022_better(ret, memchr(p, '\r', length)); ret = _vte_iso2022_better(ret, memchr(p, '\016', length)); ret = _vte_iso2022_better(ret, memchr(p, '\017', length)); #ifdef VTE_ISO2022_8_BIT_CONTROLS /* This breaks UTF-8 and other encodings which use the high bits. */ ret = _vte_iso2022_better(ret, memchr(p, 0x8e, length)); ret = _vte_iso2022_better(ret, memchr(p, 0x8f, length)); #endif return ret; }

Since the _vte_iso2022_better() function basically returns the minimum of the two pointers a speedup is possible by

• doing only one pass over the string instead of seven
• stopping as soon as a control character is found.

The attached patch makes the elapsed time drop from 14.1 seconds to 12.4 seconds on cat jarg22.txt.

Wouldn't it be much easier to use strpbrk ?

On Tue, 2004-05-25 at 22:50, Jason Tackaberry wrote:

I think it was Warren who mentioned that he has to minimize gnome-terminal when he's doing a noisy compile otherwise it significantly slows down. That's certainly true for me too (although I just toggle to another tab), but I'm not sure if the real problem is with gnome-terminal, pango, or the underlying font system -- or perhaps at layers even lower than that, like really bad or non-existent Render support in the video driver.

Gnome-terminal is really not significantly slower than xterm if they are on par font-wise, i.e. you run xterm with an AA font, or pick a bitmapped font for gnome-terminal.

=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-= Alexander Larsson Red Hat, Inc alexl@redhat.com alla@lysator.liu.se He's a fiendish one-eyed waffle chef who hangs with the wrong crowd. She's a scantily clad junkie schoolgirl with the soul of a mighty warrior. They fight crime!

Thanks for running the experiments.

Yusuf Goolamabbas wrote:

I had already run prelink -avmR since I wasn't sure if my system was prelinked out of the box or it would do it a week/two weeks subsequently

...

What is the hardware configuration of the system:

Processor (output of /proc/cpuinfo):

processor : 0 vendor_id : AuthenticAMD cpu family : 6 model : 4 model name : AMD Athlon(tm) Processor stepping : 2 cpu MHz : 756.938 cache size : 256 KB fdiv_bug : no hlt_bug : no f00f_bug : no coma_bug : no fpu : yes fpu_exception : yes cpuid level : 1 wp : yes flags : fpu vme de pse tsc msr pae mce cx8 mtrr pge mca cmov pat pse36 mmx fxsr syscall mmxext 3dnowext 3dnow bogomips : 1482.75

...

Memory:

512 MB

...

Harddisk drive:

ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx VP_IDE: IDE controller at PCI slot 0000:00:04.1 VP_IDE: chipset revision 16 VP_IDE: not 100% native mode: will probe irqs later VP_IDE: VIA vt82c686a (rev 22) IDE UDMA66 controller on pci0000:00:04.1 ide0: BM-DMA at 0xd800-0xd807, BIOS settings: hda:DMA, hdb:pio ide1: BM-DMA at 0xd808-0xd80f, BIOS settings: hdc:DMA, hdd:pio hda: ST36421A, ATA DISK drive Using cfq io scheduler

...

Video card:

PCI Vanta

+-01.0-[0000:01]----00.0 nVidia Corporation NV6 [Vanta/Vanta LT]

...

What is the software configuration of the system:

kernel being used (uname -r):

2.6.5-1.358

...

rpm versions of packages (rpm -qf `which xterm`):

xterm-179-6.EL

...

In each case you will need to exit the newly started xterm once it has started.

What is the output of:

/usr/bin/time xterm

0.13user 0.02system 0:10.59elapsed 1%CPU (0avgtext+0avgdata 0maxresident)k 0inputs+0outputs (0major+1548minor)pagefaults 0swaps

10.59 seconds elapsed? That seems rather long. To get a better lower bound and remove the human interaction you can run:

/usr/bin/time xterm -e ''

The output above indicates that xterm is not cpu-bound, only 0.15s of the time is cpu time. However, this test is not identical to bringing up an xterm via the menu, a different font is being used. It is possible that additional time is required because of the fonts. I need to find out how to select the same font as being used for the menu selected xterm.

...

What is the output of (note that the output is going to be split between the current xterm and the new xterm:

LD_DEBUG=statistics xterm

I did the followin LD_DEBUG=statistics xterm > xterm.stat 2>&1

 16607:	
 16607:	runtime linker statistics:
 16607:	  total startup time in dynamic loader: 2864925 clock cycles
 16607:	            time needed for relocation: 286987 clock cycles (10.0%)
 16607:	                 number of relocations: 0
 16607:	      number of relocations from cache: 233
 16607:	        number of relative relocations: 0
 16607:	           time needed to load objects: 2246374 clock cycles (78.4%)
 16608:	
 16608:	runtime linker statistics:
 16608:	  total startup time in dynamic loader: 409553 clock cycles
 16608:	            time needed for relocation: 15915 clock cycles (3.8%)
 16608:	                 number of relocations: 0
 16608:	      number of relocations from cache: 17
 16608:	        number of relative relocations: 0
 16608:	           time needed to load objects: 202630 clock cycles (49.4%)
 16608:	
 16608:	runtime linker statistics:
 16608:	           final number of relocations: 15
 16608:	final number of relocations from cache: 17
 16627:	
 16627:	runtime linker statistics:
 16627:	  total startup time in dynamic loader: 440201 clock cycles
 16627:	            time needed for relocation: 17764 clock cycles (4.0%)
 16627:	                 number of relocations: 0
 16627:	      number of relocations from cache: 17
 16627:	        number of relative relocations: 0
 16627:	           time needed to load objects: 207246 clock cycles (47.0%)
 16627:	
 16627:	runtime linker statistics:
 16627:	           final number of relocations: 15
 16627:	final number of relocations from cache: 17
 16607:	
 16607:	runtime linker statistics:
 16607:	           final number of relocations: 181
 16607:	final number of relocations from cache: 244

...

Also get a memory map of the xterm:

xterm & # will print out pid of background process. use the number below cat /proc/2201/maps > /tmp/xterm_maps

Lots of mappings, which is usually the case for GUI programs. Is it always slow starting up an xterm regardless of number of other xterms already on the screen? I am wondering if the slow time is due to pulling all the libraries off the disk. If the xterm startup up faster when there are already xterms, on the screen that may indicate that the time is being dominated by pulling the shared libraries from the disk into memory. How much disk activity is there when you start up xterm?

...

As root run oprofile to find out which executables and libraries are being used:

opcontrol --setup --vmlinux=/boot/vmlinux-`uname -r` --separate=library opcontrol --reset; opcontrol --start; xterm; opcontrol --shutdown opreport

arjan mentioned on IRC that oprofile needs APIC and this is not enabled on UP kernel so I can't give you this info

Yes, I forgot that you may be running as UP kernel. I usually install the smp kernel so I can get that information. But given the low cpu usage, oprofile is probably not going to help much here.

Hope the above helps, Let me know if I can assist further

Regards, Yusuf

-Will