Initial Profiling Results

Submitted by haakenso on Sat, 02/10/2007 - 05:41.

Wanted to share some numbers from an initial profiling run. The profiler ran for any classes loaded with PluginClassLoaderImpl until after the boot process finished and I went into the debugger to trigger output. Should cover most of the non-compiled-at-bootup java startup code, but I don't really know. Numbers (time and percent) are not showing up in the columns due to what looks like a bug in printf(). But too tired to work through that tonight.

Some notes on it.

-First of all, thanks to JIP(http://jiprof.sourceforge.net/) for doing the heavy lifting of the actual profiling work.
-The following packages are excluded from the results (method time that isn't showing now but is reflected in the sort will show up in parent), org.jnode.driver, org.jnode.assembler, org.jnode.boot, org.jnode.system, org.jnode.vm

+--------------------------------------+
| Most expensive methods summarized |
+--------------------------------------+

Net
------------
Count Time Pct Location
===== ==== === ========
1 org.jnode.net.ipv4.tcp.TCPTimer:run
18 org.jnode.work.WorkPlugin$WorkProcessor:process
1 org.jnode.shell.CommandShell:run
9 org.jnode.fs.service.def.FileSystemTypeManager:createType
2 org.jnode.net.service.DefaultNetworkLayerManager:configureLayer
2 org.jnode.shell.CommandShell:
1 org.jnode.fs.service.def.FileSystemPlugin:startPlugin
294 org.jnode.fs.jifs.files.JIFSFplugin:refresh
1 org.jnode.net.ipv4.config.impl.IPv4ConfigurationPlugin:startPlugin
1 org.jnode.net.ipv4.layer.IPv4NetworkLayer:
1 org.jnode.fs.service.def.FileSystemMounter:tryToMount
1 org.jnode.fs.ramfs.def.RAMFSPlugin:startPlugin
9 org.jnode.work.WorkPlugin:add
2 org.jnode.net.ipv4.config.impl.NetConfigurationData:getConfiguration
1 org.jnode.fs.service.def.FileSystemPlugin:
2 org.jnode.net.ipv4.config.impl.NetConfigurationData:isAutoConfigureUsingDhcp
1 org.jnode.awt.AWTPlugin:startPlugin
1 org.jnode.work.WorkPlugin:
1 org.jnode.fs.jifs.directories.JIFSDthreads:refresh
21 org.jnode.fs.service.def.FileSystemAPIImpl:getEntry
1 org.jnode.fs.iso9660.ISO9660FileSystem:
1 org.jnode.fs.jifs.directories.JIFSDrootDir:checkInit
5378 org.jnode.fs.jifs.JIFSFile:addStringln
677 org.jnode.fs.jifs.JIFSFile:
2 org.jnode.awt.font.def.DefaultFontManager:configureProvider
3 org.jnode.fs.service.def.FileSystemPlugin:registerFileSystem
2 org.jnode.fs.jifs.JIFileSystemType:create
2 org.jnode.fs.iso9660.ISO9660FileSystemType:create
1 org.jnode.shell.CommandShell:main
1 org.jnode.fs.jifs.def.JIFSPlugin:
3 org.jnode.fs.service.def.VirtualMountEntry:
2 org.jnode.fs.ramfs.RAMFileSystemType:create
1 org.jnode.fs.service.def.FileSystemTypeManager:
1 org.jnode.log4j.config.Log4jConfigurePlugin:startPlugin
2 org.jnode.fs.jifs.directories.JIFSDpluginJars:
13 org.jnode.fs.service.def.FileSystemAPIImpl:getParentDirectoryEntry
1 org.jnode.fs.service.def.FileSystemAPIImpl:mkDir
1 org.jnode.fs.iso9660.PrimaryVolumeDescriptor:
1 org.jnode.fs.service.def.FileSystemAPIImpl:
1 org.jnode.debugger.Debugger:run
1 org.jnode.fs.jifs.def.JIFSExtension:
1 org.jnode.fs.iso9660.ISO9660Volume:
2 org.jnode.net.ipv4.config.impl.NetDeviceMonitor:configureDevice
1 org.jnode.net.ipv4.tcp.TCPProtocol:
1 org.jnode.debugger.DebuggerPlugin:startPlugin
1 org.jnode.fs.iso9660.ISO9660FileSystemType:supports
1 org.jnode.fs.iso9660.EntryRecord:
1 org.jnode.net.ipv4.config.impl.IPv4ConfigurationPlugin$1:execute
3 org.jnode.fs.iso9660.ISO9660Volume:readFromLBN
2 org.jnode.shell.help.Help$Info:
1 org.jnode.debugger.Debugger:systemTrigger
1 org.jnode.debugger.Debugger:keyPressed
1 org.jnode.fs.service.def.FileSystemMounter:asyncDeviceStarted
97 org.jnode.net.ipv4.tcp.TCPControlBlockList:timeout
1 org.jnode.net.service.DefaultNetworkLayerManager:refreshNetworkLayers
1 org.jnode.protocol.ProtocolHandlerFactoryPlugin:startPlugin
1 org.jnode.fs.jifs.directories.JIFSDrootDir:setup
294 org.jnode.fs.jifs.files.JIFSFpluginJar:refresh
3 org.jnode.fs.service.def.FileSystemPlugin:mount
5701 org.jnode.fs.jifs.JIFSFile:addString
1 org.jnode.fs.service.def.FileSystemTypeManager:refreshFileSystemTypes
1 org.jnode.fs.jifs.def.JIFSPlugin:startPlugin
323 org.jnode.fs.jifs.JIFSFile:refresh
3 org.jnode.fs.service.def.FileSystemAPIImpl:mount
1 org.jnode.shell.def.ShellPlugin:startPlugin
1 org.jnode.protocol.ProtocolHandlerFactoryPlugin:setHandlerFactory
2 org.jnode.fs.jifs.def.JIFSExtension:addEntry
1 org.jnode.work.WorkPlugin:startPlugin
2 org.jnode.fs.jifs.directories.JIFSDplugins:
1 org.jnode.fs.jifs.def.JIFSExtension:refresh
1 org.jnode.fs.jifs.directories.JIFSDpluginJars:refresh
1 org.jnode.fs.jifs.directories.JIFSDthreads:addGroup
99 org.jnode.work.WorkPlugin:isStartFinished
1 org.jnode.fs.service.def.FileSystemMounter:start
3 org.jnode.fs.service.def.FileSystemManager:registerFileSystem
1 org.jnode.awt.font.truetype.TTFontProvider:
2 org.jnode.shell.Line:start
3 org.jnode.fs.service.def.VirtualDirEntry:addMount
1 org.jnode.net.service.NetPlugin:
2 org.jnode.shell.alias.def.DefaultAliasManager:
1 org.jnode.fs.iso9660.ISO9660FileSystem:getRootEntry
2 org.jnode.fs.jifs.files.JIFSFuptime:
1 org.jnode.net.ipv4.udp.UDPProtocol:
1 org.jnode.fs.ramfs.RAMFileSystem:
1 org.jnode.partitions.service.def.PartitionTableTypeManager:createType
1 org.jnode.awt.font.def.DefaultFontManager:updateFontProviders
2 org.jnode.work.WorkPlugin:addWorker
52 org.jnode.fs.jifs.files.JIFSFthread:refresh
1 org.jnode.net.arp.ARPNetworkLayer:
1 org.jnode.fs.service.def.FileSystemMounter$1:execute
3 org.jnode.fs.iso9660.VolumeDescriptor:getType
2 org.jnode.fs.ramfs.RAMFileSystem:getRootEntry
1 org.jnode.shell.alias.def.DefaultAliasManager:refreshAliases
1 org.jnode.partitions.service.def.PartitionTableTypeManager:refreshPartitionTableTypes
1 org.jnode.net.arp.ARPCache:
1 org.jnode.net.ipv4.tcp.TCPTimer:
346 org.jnode.fs.jifs.JIFSDirectory:addFSE
3 org.jnode.shell.help.Argument:
1 org.jnode.debugger.Debugger$1:run
1 org.jnode.log4j.config.VirtualConsoleAppender:
1 org.jnode.awt.util.BitmapGraphics$BitmapGraphics32bpp:
1 org.jnode.debugger.Debugger:setPreferredListener
9 org.jnode.work.Work:
4 org.jnode.net.ipv4.layer.IPv4NetworkLayer:registerProtocol
2 org.jnode.fs.service.def.FileSystemPlugin:getFileSystemTypeForNameSystemTypes
1 org.jnode.fs.iso9660.ISO9660Volume:getRootDirectoryEntry
1 org.jnode.shell.Line:setContent
1 org.jnode.fs.jifs.directories.JIFSDplugins:refresh
1 org.jnode.awt.font.def.DefaultFontManager:start
6 org.jnode.fs.service.def.FileSystemMounter:deviceStarted
9 org.jnode.work.WorkUtils:add
1 org.jnode.net.service.NetPlugin:startPlugin
1 org.jnode.fs.iso9660.VolumeDescriptor:
1 org.jnode.fs.jifs.directories.JIFSDrootDir:getEntry
2 org.jnode.fs.jifs.files.JIFSFversion:
1 org.jnode.fs.ramfs.def.RAMFSPlugin:
1 org.jnode.awt.font.def.FontPlugin:
1 org.jnode.protocol.ProtocolHandlerFactoryPlugin:
1 org.jnode.fs.service.def.FileSystemMounter:
1 org.jnode.fs.service.def.VirtualFS:
1 org.jnode.net.ipv4.icmp.ICMPProtocol:
2 org.jnode.fs.jifs.directories.JIFSDthreads:
1 org.jnode.fs.service.def.FileSystemPlugin:fileSystemTypes
1 org.jnode.net.service.DefaultNetworkLayerManager:
1 org.jnode.debugger.DebuggerPlugin:
13 org.jnode.fs.service.def.FSEntryCache:getEntry
1 org.jnode.partitions.service.def.PartitionTablePlugin:
1 org.jnode.fs.jifs.files.JIFSFuptime:refresh
11 org.jnode.fs.service.def.FileSystemAPIImpl:stripParentPath
2 org.jnode.awt.font.spi.AbstractFontProvider:
12 org.jnode.fs.jifs.JIFSDirectory:
1 org.jnode.awt.swingpeers.SwingPeersPlugin:startPlugin
22 org.jnode.debugger.DebuggerPlugin:addListeners
1 org.jnode.net.ipv4.layer.IPv4Sender:
3 org.jnode.net.ethernet.EthernetAddress:
6 org.jnode.net.ethernet.EthernetAddress:get
1 org.jnode.shell.CommandShell:prompt
1 org.jnode.net.ipv4.config.impl.NetDeviceMonitor:configureDevices
1 org.jnode.awt.VMImageAPIImpl:
1 org.jnode.awt.font.def.FontPlugin:startPlugin
4 org.jnode.fs.iso9660.Descriptor:getUInt32LE
1 org.jnode.fs.service.def.VirtualFSDevice:
2 org.jnode.fs.service.def.VirtualFSDevice$VirtualFSDriver:
2 org.jnode.shell.help.Parameter:
1 org.jnode.fs.iso9660.EntryRecord:getFileIdentifier
1 org.jnode.fs.fat.FatFileSystemType:getName
1 org.jnode.fs.smbfs.SMBFileSystemType:supports
16 org.jnode.fs.jifs.files.JIFSFfragmentJar:
1 org.jnode.shell.ThreadCommandInvoker:
1 org.jnode.partitions.service.def.PartitionTableTypeManager:
1 org.jnode.shell.alias.def.DefaultAliasManager:createAliasManager
89 org.jnode.shell.alias.def.DefaultAliasManager:createAlias
163 org.jnode.fs.jifs.files.JIFSFpluginJar:
3 org.jnode.fs.iso9660.Descriptor:getDChars
1 org.jnode.shell.DefaultCommandInvoker:
1 org.jnode.fs.fat.BootSector:
147 org.jnode.fs.jifs.files.JIFSFplugin:
1 org.jnode.net.ipv4.config.impl.ConfigurationProcessor:start
18 org.jnode.work.Work:toString
48 org.jnode.fs.jifs.files.JIFSFfragmentJar:refresh
1 org.jnode.debugger.RootState:
26 org.jnode.fs.jifs.files.JIFSFthread:
1 org.jnode.fs.jifs.directories.JIFSDrootDir:
2 org.jnode.fs.jifs.files.JIFSFmemory:
2 org.jnode.fs.ramfs.RAMFileSystem:isClosed
1 org.jnode.shell.help.argument.FileArgument:
1 org.jnode.net.ipv4.tcp.TCPProtocol$1:run
1 org.jnode.fs.service.def.VirtualDirEntry:addDirectory
2 org.jnode.fs.jifs.files.JIFSFdevices:
1 org.jnode.net.ipv4.tcp.TCPControlBlockList:
1 org.jnode.net.ipv4.raw.RAWProtocol:
1 org.jnode.fs.jifs.JIFileSystem:
1 org.jnode.protocol.ProtocolHandlerFactoryPlugin$1:run
1 org.jnode.awt.util.BitmapGraphics:create32bppInstance
2 org.jnode.fs.service.def.FileSystemPlugin:getFileSystem
1 org.jnode.shell.help.Syntax:
6 org.jnode.fs.service.def.VirtualDirEntry:isDirectory
1 org.jnode.shell.CommandHistory:
1 org.jnode.partitions.service.def.PartitionTablePlugin:startPlugin
1 org.jnode.net.ipv4.udp.UDPProtocol$1:run
1 org.jnode.fs.service.def.VirtualMountEntry:isDirectory
1 org.jnode.fs.smbfs.SMBFileSystemType:
1 org.jnode.fs.service.def.FileSystemAPIImpl:getName
1 org.jnode.net.ethernet.EthernetAddress:toString
1 org.jnode.fs.jifs.JIFileSystemType:
4 org.jnode.fs.service.def.VirtualDirEntry:modified
1 org.jnode.fs.fat.FatFileSystemType:
1 org.jnode.shell.help.argument.AliasArgument:
1 org.jnode.debugger.RootState:process
1 org.jnode.debugger.Debugger:reset
1 org.jnode.net.ipv4.tcp.TCPProtocol:getProtocolID
1 org.jnode.fs.service.def.FileSystemAPIImpl:open
323 org.jnode.fs.jifs.JIFSFile:cleardata
97 org.jnode.net.ipv4.IPv4ControlBlockList:iterator
1 org.jnode.fs.jifs.JIFSDirectory:getEntry
1 org.jnode.net.arp.ARPStatistics:
4 org.jnode.fs.ramfs.RAMDirectory:getDirectory
16 org.jnode.fs.service.def.FileSystemAPIImpl:getParentPath
5 org.jnode.net.NetPermission:
1 org.jnode.fs.jifs.JIFSDirectory:refresh
1 org.jnode.net.ipv4.udp.UDPStatistics:
9 org.jnode.work.WorkPlugin:getFreeProcessors
1 org.jnode.fs.jifs.directories.JIFSDthreads$1:run
9 org.jnode.work.WorkPlugin:incWorkEndCounter
1 org.jnode.net.ipv4.config.impl.ConfigurationProcessor:
1 org.jnode.net.ipv4.tcp.TCPStatistics:
342 org.jnode.fs.jifs.JIFSFile:getName
1 org.jnode.net.ipv4.layer.IPv4Statistics:
3 org.jnode.fs.ramfs.RAMDirectory:isDirectory
1 org.jnode.shell.CommandShell$1:run
3 org.jnode.fs.jifs.JIFSDirectory:clear
2 org.jnode.net.ipv4.config.impl.NetDeviceMonitor:deviceStarted
2 org.jnode.awt.font.renderer.RenderContext:
11 org.jnode.fs.iso9660.Descriptor:getUInt8
1 org.jnode.fs.ftpfs.FTPFileSystemType:getName
9 org.jnode.work.WorkPlugin:incWorkStartCounter
1 org.jnode.protocol.ProtocolHandlerFactoryPlugin:reloadHandlers
1 org.jnode.awt.font.def.DefaultFontManager:
5 org.jnode.fs.jifs.JIFSFile:setParent
1 org.jnode.awt.font.bdf.BDFFontProvider:
1 org.jnode.fs.iso9660.Descriptor:getAChars
1 org.jnode.net.ipv4.IPv4ControlBlockList:
1 org.jnode.fs.jifs.directories.JIFSDthreads$2:run
6 org.jnode.fs.jifs.JIFSDirectory:getName
1 org.jnode.fs.jifs.files.JIFSFversion:refresh
5 org.jnode.fs.service.def.VirtualDirEntry:getEntry
1 org.jnode.net.ipv4.config.impl.NetConfigurationData:
1 org.jnode.net.ipv4.IPv4RoutingTable:
8 org.jnode.fs.service.def.FSEntryCache:setEntry
1 org.jnode.net.service.DefaultNetworkLayerManager:getQueue
1 org.jnode.fs.ftpfs.FTPFileSystemType:
1 org.jnode.net.ipv4.icmp.ICMPUtils:
1 org.jnode.net.ipv4.config.impl.IPv4ConfigurationPlugin$1:
1 org.jnode.shell.Line:startModif
1 org.jnode.debugger.Debugger:keyReleased
1 org.jnode.fs.service.def.VirtualMountEntry:getDirectory
1 org.jnode.net.ipv4.tcp.TCPTimer:autoName
1 org.jnode.desktop.DesktopPlugin:
2 org.jnode.fs.iso9660.Descriptor:
1 org.jnode.shell.def.DefaultShellManager:
1 org.jnode.debugger.DebugState:
1 org.jnode.fs.jifs.JIFSDirectory:setName
1 org.jnode.net.ipv4.config.impl.ConfigurationServiceImpl:
3 org.jnode.fs.ramfs.RAMDirectory:getEntry
2 org.jnode.fs.iso9660.Descriptor:getUInt32Both
1 org.jnode.shell.Line:moveEnd
1 org.jnode.net.ipv4.layer.IPv4NetworkLayer:getProtocolID
1 org.jnode.awt.util.BitmapGraphics:
1 org.jnode.net.ipv4.udp.UDPProtocol:getProtocolID
1 org.jnode.fs.ramfs.RAMDirectory:isValid
1 org.jnode.shell.CommandShell$1:
1 org.jnode.fs.spi.AbstractFileSystem:
3 org.jnode.fs.service.def.FileSystemAPIImpl:fileExists
1 org.jnode.debugger.DebugState:getParent
1 org.jnode.net.ipv4.udp.UDPProtocol:access$000
1 org.jnode.desktop.DesktopPlugin:startPlugin
2 org.jnode.fs.iso9660.ISO9660FileSystemType:getName
2 org.jnode.work.WorkPlugin$WorkProcessor:
1 org.jnode.net.ipv4.udp.UDPDatagramSocketImplFactory:
1 org.jnode.net.ipv4.tcp.TCPSocketImplFactory:
2 org.jnode.net.ipv4.tcp.TCPProtocol:access$000
1 org.jnode.net.ipv4.udp.UDPProtocol$1:
1 org.jnode.net.ipv4.raw.RAWStatistics:
1 org.jnode.fs.jifs.JIFileSystem:getDevice
1 org.jnode.fs.service.def.VirtualFSDevice$VirtualFSDriver:startDevice
1 org.jnode.fs.jfat.FatFileSystemType:getName
1 org.jnode.shell.Line:
1 org.jnode.fs.ext2.Ext2FileSystemType:
1 org.jnode.net.service.NetAPIImpl:
1 org.jnode.shell.ShellUtils:getShellManager
1 org.jnode.net.ipv4.icmp.ICMPStatistics:
89 org.jnode.shell.alias.def.DefaultAliasManager$Alias:
1 org.jnode.shell.def.ShellPlugin:
2 org.jnode.awt.font.renderer.RenderCache:
1 org.jnode.shell.Line:endModif
1 org.jnode.shell.def.DefaultShellManager:registerShell
1 org.jnode.protocol.ProtocolHandlerFactoryPlugin$1:
1 org.jnode.debugger.Debugger$1:
1 org.jnode.fs.ntfs.NTFSFileSystemType:getName
1 org.jnode.partitions.ibm.IBMPartitionTableType:
1 org.jnode.shell.help.def.SystemHelpPlugin:
1 org.jnode.fs.ramfs.RAMFileSystemType:
1 org.jnode.net.ipv4.config.impl.IPv4ConfigurationPlugin:
2 org.jnode.fs.jifs.JIFileSystemType:getName
2 org.jnode.fs.service.def.FileSystemManager:getFileSystem
3 org.jnode.fs.ramfs.RAMDirectory:
1 org.jnode.net.ipv4.tcp.TCPProtocol$1:
1 org.jnode.fs.jfat.FatFileSystemType:
3 org.jnode.shell.help.CommandLineElement:
4 org.jnode.fs.jifs.JIFSDirectory:setParent
2 org.jnode.shell.CommandShell:getErrorStream
2 org.jnode.fs.iso9660.Descriptor:getUInt16Both
1 org.jnode.net.arp.ARPNetworkLayer:getProtocolID
2 org.jnode.fs.ramfs.RAMFileSystemType:getName
1 org.jnode.net.ipv4.layer.IPv4NetworkLayer:getRoutingTable
1 org.jnode.awt.swingpeers.SwingPeersPlugin:
1 org.jnode.shell.CommandShell:isExitted
2 org.jnode.fs.iso9660.Descriptor:getUInt32BE
3 org.jnode.debugger.DebuggerPlugin:deviceStarted
1 org.jnode.fs.jifs.directories.JIFSDthreads$2:
1 org.jnode.net.ipv4.config.impl.NetDeviceMonitor:
2 org.jnode.fs.service.def.VirtualDirEntry:
1 org.jnode.net.ipv4.layer.IPv4NetworkLayer:getStatistics
1 org.jnode.awt.font.truetype.TTFPlugin:
1 org.jnode.fs.ntfs.NTFSFileSystemType:
1 org.jnode.fs.jifs.directories.JIFSDthreads$1:
1 org.jnode.fs.iso9660.EntryRecord:isDirectory
1 org.jnode.fs.jifs.JIFSDirectory:getDirectory
1 org.jnode.awt.font.truetype.TTFPlugin:startPlugin
2 org.jnode.fs.service.def.FileSystemTypeManager:getSystemType
1 org.jnode.debugger.Debugger:
1 org.jnode.fs.service.def.FileSystemTypeManager:fileSystemTypes
1 org.jnode.net.ipv4.config.impl.IPv4ConfigurationPlugin:access$000
2 org.jnode.fs.jifs.JIFileSystem:getRootEntry
1 org.jnode.fs.iso9660.ISO9660FileSystemType:
1 org.jnode.fs.service.def.FSEntryCache:
1 org.jnode.fs.ftpfs.FTPFileSystemType:supports
1 org.jnode.fs.iso9660.PrimaryVolumeDescriptor:getRootDirectoryEntry
1 org.jnode.net.ipv4.config.impl.IPv4ConfigurationPlugin:access$100
10 org.jnode.fs.service.def.VirtualDirEntry:getDirectory
8 org.jnode.fs.service.def.VirtualFS:getRootEntry
1 org.jnode.fs.spi.AbstractFileSystem:getFSApi
1 org.jnode.net.ipv4.raw.RAWProtocol:getProtocolID
1 org.jnode.fs.spi.AbstractFileSystem:getDevice
2 org.jnode.fs.service.def.FileSystemPlugin:getApi
1 org.jnode.fs.smbfs.SMBFileSystemType:getName
1 org.jnode.fs.iso9660.ISO9660Entry:
1 org.jnode.log4j.config.Log4jConfigurePlugin:
1 org.jnode.fs.ramfs.RAMFileSystem:getDevice
1 org.jnode.fs.ext2.Ext2FileSystemType:getName
1 org.jnode.awt.AWTPlugin:
1 org.jnode.fs.service.def.FileHandleManager:
1 org.jnode.fs.service.def.FileSystemMounter$1:
1 org.jnode.shell.CommandShell:getConsole
1 org.jnode.fs.service.def.FileSystemManager:
2 org.jnode.fs.ramfs.RAMDirectory:addDirectory
1 org.jnode.net.ipv4.icmp.ICMPProtocol:getProtocolID
1 org.jnode.partitions.ibm.IBMPartitionTableType:getName
1 org.jnode.fs.jifs.JIFSFile:setName

‹ Derby & Jnode waht about java ›

oh, hard to understand

Submitted by surfeit on Sun, 02/11/2007 - 01:43.

hi, haakenso, can you give a chart and a reasonable explanation?

Hi haakenso, this is very

Submitted by Peter on Sat, 02/10/2007 - 14:46.

Hi haakenso,

this is very interessting. I hope you'll keep up your good work and give us more stats Smiling I personally am interessted in the GUI classes, so if you come to that point, it would be nice to see stats about startawt Eye-wink

Though are you sure the numbers are correct? I'm wondering about the jifs classes. Why do they have so high counts compared to the other classes/methods?

With numbers (long numbers)

Submitted by haakenso on Sat, 02/10/2007 - 17:31.

Object Allocations during Startup

Submitted by haakenso on Sat, 02/10/2007 - 18:23.

Here is the top of the object allocation list during startup.

Only includes classes that I can instrument so most of the meat (String, ints, etc) will not be included.

May still provide value to someone.

Count Class Name
===== ==========
341 org.jnode.fs.jifs.JIFSFile
163 org.jnode.fs.jifs.files.JIFSFpluginJar
147 org.jnode.fs.jifs.files.JIFSFplugin
89 org.jnode.shell.alias.def.DefaultAliasManager$Alias
26 org.jnode.fs.jifs.files.JIFSFthread
16 org.jnode.fs.jifs.files.JIFSFfragmentJar
9 org.jnode.work.Work
6 org.jnode.fs.jifs.JIFSDirectory
5 org.jnode.net.NetPermission
3 org.jnode.net.ethernet.EthernetAddress
3 org.jnode.fs.service.def.VirtualMountEntry
3 org.jnode.shell.help.CommandLineElement
3 org.jnode.fs.ramfs.RAMDirectory
2 org.jnode.awt.font.renderer.RenderCache
2 org.jnode.awt.font.spi.AbstractFontProvider
2 org.jnode.work.WorkPlugin$WorkProcessor
2 org.jnode.awt.font.renderer.RenderContext
2 org.jnode.fs.service.def.VirtualDirEntry
2 org.jnode.fs.iso9660.Descriptor
2 org.jnode.shell.alias.def.DefaultAliasManager
2 org.jnode.shell.help.Argument
1 org.jnode.fs.jifs.JIFileSystem
1 org.jnode.fs.service.def.VirtualFSDevice$VirtualFSDriver
1 org.jnode.debugger.Debugger$1
1 org.jnode.fs.jifs.directories.JIFSDrootDir
1 org.jnode.fs.ftpfs.FTPFileSystemType
1 org.jnode.desktop.DesktopPlugin
1 org.jnode.net.ipv4.IPv4RoutingTable
1 org.jnode.net.ipv4.tcp.TCPStatistics
1 org.jnode.fs.iso9660.ISO9660Volume
1 org.jnode.fs.iso9660.ISO9660FileSystemType
1 org.jnode.awt.font.truetype.TTFontProvider
1 org.jnode.debugger.RootState
1 org.jnode.fs.service.def.FileSystemManager
1 org.jnode.net.ipv4.tcp.TCPTimer
1 org.jnode.shell.CommandShell
1 org.jnode.net.ipv4.layer.IPv4Sender
1 org.jnode.fs.service.def.VirtualFS
1 org.jnode.fs.ramfs.def.RAMFSPlugin
1 org.jnode.debugger.DebuggerPlugin
1 org.jnode.fs.jifs.directories.JIFSDpluginJars
1 org.jnode.protocol.ProtocolHandlerFactoryPlugin$1
1 org.jnode.fs.jifs.files.JIFSFmemory
1 org.jnode.awt.VMImageAPIImpl
1 org.jnode.fs.service.def.VirtualFSDevice
1 org.jnode.fs.service.def.FileSystemPlugin
1 org.jnode.net.ipv4.config.impl.IPv4ConfigurationPlugin
1 org.jnode.net.ipv4.config.impl.ConfigurationProcessor
1 org.jnode.net.ipv4.config.impl.ConfigurationServiceImpl
1 org.jnode.fs.jifs.files.JIFSFversion
1 org.jnode.net.ipv4.tcp.TCPProtocol$1
1 org.jnode.awt.font.truetype.TTFPlugin
1 org.jnode.shell.ThreadCommandInvoker
1 org.jnode.fs.jifs.def.JIFSPlugin
1 org.jnode.fs.ramfs.RAMFileSystemType
1 org.jnode.shell.help.argument.AliasArgument
1 org.jnode.fs.service.def.FileHandleManager
1 org.jnode.net.ipv4.raw.RAWProtocol
1 org.jnode.shell.help.def.SystemHelpPlugin
1 org.jnode.fs.jifs.JIFileSystemType
1 org.jnode.shell.CommandHistory

design of jifs

Submitted by Trickkiste on Tue, 02/13/2007 - 16:14.

Hi,

the design of jifs is not quite well. I added my concern via the following comment to the refresh() method of e.g. JIFSDplugins :


// this has to be improved
// just add new ones and delete old ones
// now it does delete all files and (re)create all ones


(A refresh in this dir causes new plugin-info files, and they cause many calls of addstring() and or addstringln())


So, what may help is:

1. do not include jifs (you will miss the plugin-jar directory done by Levente)

2. just refresh when needed, e.g. a plugin starts / stops

Since I have nearly no time to work on JNode since some month now I was not able to change that. But your results verify my concerns.



Andreas

Hi Trickkiste, If I look at

Submitted by Peter on Tue, 02/13/2007 - 17:51.

Hi Trickkiste,

If I look at only one line:

5378,435.899999999999976125125,0.10999999999999997111113,org.jnode.fs.jifs.JIFSFile:addStringln

The method gets called 5378 times and needs 435milliseconds, which gives 5378*435 = 2339 seconds = 39 minutes. At least for me, JNode starts up a bit faster than 40 minutes Smiling Either I can't read the stats or there's an error in the generated tabluar.

Anyway, thanks for the hint, it's allways good to find things that could be optimized Smiling

Aggregate numbers

Submitted by haakenso on Tue, 02/13/2007 - 18:25.

The numbers for time are aggregates of every invocation of that method. It's sorted this way so a method that is called a million times but takes only a short amount of time will be sorted above a method that is called once but takes a slightly longer amount of time. Also, the system is a lot slower when profiling bootup. While it's not 40 minutes, it's not quick either. Times should only be used relative to other times except to sanity check.

How do you track sub-millisecond times in a system that only supports a millisecond-precision clock? I don't Eye-wink It's just grabbing the millisecond time and diff'ing off that. Statistically I would guess that something like 5000 method calls will cross the millisecond boundary about the correct number of times. If you had a sub-millisecond function that was called twice the numbers could be incredibly off. And even for the 5000 calls case, I'm sure it could be shown to be a totally incorrect value. Give me a nano-second timer and I'll use it in a heartbeat. Eye-wink

Initial profiling results and all the appropriate caveats apply....

-C

since 1.5 : System.nanoTime()

Submitted by Fabien D on Wed, 02/14/2007 - 19:04.

Since 1.5, there is since 1.5 : System.nanoTime().
It is "implemented" by Classpath : in fact, it is delegating the work to VMSystem.nanoTime(), which is not yet implemented in JNode.

I have found that.
but doesn't seems reliable (see remarks in the page)

Fabien

my blog (in english and french)

System.nanoTime() now in JNode

Submitted by Peter on Wed, 02/14/2007 - 23:03.

Thanks Fabien,

that works great for the moment. On first call to nanoTime the MHz of the CPU get calculated (is there a real solution to get the CPU's MHz??) on each further call the mhz are used to calculate the nanotime using cpu cycles.

Code is in svn, "org.jnode.test.NanoTimeTest" to test the accuracy Eye-wink