Re: Results from xterm startup experiment

[Will Cohen <wcohen redhat com>]

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