DEVELOPER_README revision 7:1e3f411f47bf
1This document describes system properties that are used for internal 2debugging and instrumentation purposes, along with the system loggers, 3which are used for the same thing. 4 5This document is intended as a developer resource, and it is not 6needed as Nashorn documentation for normal usage. Flags and system 7properties described herein are subject to change without notice. 8 9===================================== 101. System properties used internally 11===================================== 12 13This documentation of the system property flags assume that the 14default value of the flag is false, unless otherwise specified. 15 16SYSTEM PROPERTY: -Dnashorn.unstable.relink.threshold=x 17 18This property controls how many call site misses are allowed before a 19callsite is relinked with "apply" semantics to never change again. 20In the case of megamorphic callsites, this is necessary, or the 21program would spend all its time swapping out callsite targets. Dynalink 22has a default value (currently 8 relinks) for this property if it 23is not explicitly set. 24 25 26SYSTEM PROPERTY: -Dnashorn.callsiteaccess.debug 27 28See the description of the access logger below. This flag is 29equivalent to enabling the access logger with "info" level. 30 31 32SYSTEM PROPERTY: -Dnashorn.compiler.ints.disable 33 34This flag prevents ints and longs (non double values) from being used 35for any primitive representation in the lowered IR. This is default 36false, i.e Lower will attempt to use integer variables as long as it 37can. For example, var x = 17 would try to use x as an integer, unless 38other operations occur later that require coercion to wider type, for 39example x *= 17.1; 40 41 42SYSTEM PROPERTY: -Dnashorn.compiler.intarithmetic 43 44Arithmetic operations in Nashorn (except bitwise ones) typically 45coerce the operands to doubles (as per the JavaScript spec). To switch 46this off and remain in integer mode, for example for "var x = a&b; var 47y = c&d; var z = x*y;", use this flag. This will force the 48multiplication of variables that are ints to be done with the IMUL 49bytecode and the result "z" to become an int. 50 51WARNING: Note that is is experimental only to ensure that type support 52exists for all primitive types. The generated code is unsound. This 53will be the case until we do optimizations based on it. There is a CR 54in Nashorn to do better range analysis, and ensure that this is only 55done where the operation can't overflow into a wider type. Currently 56no overflow checking is done, so at the moment, until range analysis 57has been completed, this option is turned off. 58 59We've experimented by using int arithmetic for everything and putting 60overflow checks afterwards, which would recompute the operation with 61the correct precision, but have yet to find a configuration where this 62is faster than just using doubles directly, even if the int operation 63does not overflow. Getting access to a JVM intrinsic that does branch 64on overflow would probably alleviate this. 65 66There is also a problem with this optimistic approach if the symbol 67happens to reside in a local variable slot in the bytecode, as those 68are strongly typed. Then we would need to split large sections of 69control flow, so this is probably not the right way to go, while range 70analysis is. There is a large difference between integer bytecode 71without overflow checks and double bytecode. The former is 72significantly faster. 73 74 75SYSTEM PROPERTY: -Dnashorn.codegen.debug, -Dnashorn.codegen.debug.trace=<x> 76 77See the description of the codegen logger below. 78 79 80SYSTEM_PROPERTY: -Dnashorn.fields.debug 81 82See the description on the fields logger below. 83 84 85SYSTEM PROPERTY: -Dnashorn.fields.dual 86 87When this property is true, Nashorn will attempt to use primitive 88fields for AccessorProperties (currently just AccessorProperties, not 89spill properties). Memory footprint for script objects will increase, 90as we need to maintain both a primitive field (a long) as well as an 91Object field for the property value. Ints are represented as the 32 92low bits of the long fields. Doubles are represented as the 93doubleToLongBits of their value. This way a single field can be used 94for all primitive types. Packing and unpacking doubles to their bit 95representation is intrinsified by the JVM and extremely fast. 96 97While dual fields in theory runs significantly faster than Object 98fields due to reduction of boxing and memory allocation overhead, 99there is still work to be done to make this a general purpose 100solution. Research is ongoing. 101 102In the future, this might complement or be replaced by experimental 103feature sun.misc.TaggedArray, which has been discussed on the mlvm 104mailing list. TaggedArrays are basically a way to share data space 105between primitives and references, and have the GC understand this. 106 107As long as only primitive values are written to the fields and enough 108type information exists to make sure that any reads don't have to be 109uselessly boxed and unboxed, this is significantly faster than the 110standard "Objects only" approach that currently is the default. See 111test/examples/dual-fields-micro.js for an example that runs twice as 112fast with dual fields as without them. Here, the compiler, can 113determine that we are dealing with numbers only throughout the entire 114property life span of the properties involved. 115 116If a "real" object (not a boxed primitive) is written to a field that 117has a primitive representation, its callsite is relinked and an Object 118field is used forevermore for that particular field in that 119PropertyMap and its children, even if primitives are later assigned to 120it. 121 122As the amount of compile time type information is very small in a 123dynamic language like JavaScript, it is frequently the case that 124something has to be treated as an object, because we don't know any 125better. In reality though, it is often a boxed primitive is stored to 126an AccessorProperty. The fastest way to handle this soundly is to use 127a callsite typecheck and avoid blowing the field up to an Object. We 128never revert object fields to primitives. Ping-pong:ing back and forth 129between primitive representation and Object representation would cause 130fatal performance overhead, so this is not an option. 131 132For a general application the dual fields approach is still slower 133than objects only fields in some places, about the same in most cases, 134and significantly faster in very few. This is due the program using 135primitives, but we still can't prove it. For example "local_var a = 136call(); field = a;" may very well write a double to the field, but the 137compiler dare not guess a double type if field is a local variable, 138due to bytecode variables being strongly typed and later non 139interchangeable. To get around this, the entire method would have to 140be replaced and a continuation retained to restart from. We believe 141that the next steps we should go through are instead: 142 1431) Implement method specialization based on callsite, as it's quite 144frequently the case that numbers are passed around, but currently our 145function nodes just have object types visible to the compiler. For 146example "var b = 17; func(a,b,17)" is an example where two parameters 147can be specialized, but the main version of func might also be called 148from another callsite with func(x,y,"string"). 149 1502) This requires lazy jitting as the functions have to be specialized 151per callsite. 152 153Even though "function square(x) { return x*x }" might look like a 154trivial function that can always only take doubles, this is not 155true. Someone might have overridden the valueOf for x so that the 156toNumber coercion has side effects. To fulfil JavaScript semantics, 157the coercion has to run twice for both terms of the multiplication 158even if they are the same object. This means that call site 159specialization is necessary, not parameter specialization on the form 160"function square(x) { var xd = (double)x; return xd*xd; }", as one 161might first think. 162 163Generating a method specialization for any variant of a function that 164we can determine by types at compile time is a combinatorial explosion 165of byte code (try it e.g. on all the variants of am3 in the Octane 166benchmark crypto.js). Thus, this needs to be lazy 167 1683) Possibly optimistic callsite writes, something on the form 169 170x = y; //x is a field known to be a primitive. y is only an object as 171far as we can tell 172 173turns into 174 175try { 176 x = (int)y; 177} catch (X is not an integer field right now | ClassCastException e) { 178 x = y; 179} 180 181Mini POC shows that this is the key to a lot of dual field performance 182in seemingly trivial micros where one unknown object, in reality 183actually a primitive, foils it for us. Very common pattern. Once we 184are "all primitives", dual fields runs a lot faster than Object fields 185only. 186 187We still have to deal with objects vs primitives for local bytecode 188slots, possibly through code copying and versioning. 189 190 191SYSTEM PROPERTY: -Dnashorn.compiler.symbol.trace=<x> 192 193When this property is set, creation and manipulation of any symbol 194named "x" will show information about when the compiler changes its 195type assumption, bytecode local variable slot assignment and other 196data. This is useful if, for example, a symbol shows up as an Object, 197when you believe it should be a primitive. Usually there is an 198explanation for this, for example that it exists in the global scope 199and type analysis has to be more conservative. In that case, the stack 200trace upon type change to object will usually tell us why. 201 202 203SYSTEM PROPERTY: nashorn.lexer.xmlliterals 204 205If this property it set, it means that the Lexer should attempt to 206parse XML literals, which would otherwise generate syntax 207errors. Warning: there are currently no unit tests for this 208functionality. 209 210XML literals, when this is enabled, end up as standard LiteralNodes in 211the IR. 212 213 214SYSTEM_PROPERTY: nashorn.debug 215 216If this property is set to true, Nashorn runs in Debug mode. Debug 217mode is slightly slower, as for example statistics counters are enabled 218during the run. Debug mode makes available a NativeDebug instance 219called "Debug" in the global space that can be used to print property 220maps and layout for script objects, as well as a "dumpCounters" method 221that will print the current values of the previously mentioned stats 222counters. 223 224These functions currently exists for Debug: 225 226"map" - print(Debug.map(x)) will dump the PropertyMap for object x to 227stdout (currently there also exist functions called "embedX", where X 228is a value from 0 to 3, that will dump the contents of the embed pool 229for the first spill properties in any script object and "spill", that 230will dump the contents of the growing spill pool of spill properties 231in any script object. This is of course subject to change without 232notice, should we change the script object layout. 233 234"methodHandle" - this method returns the method handle that is used 235for invoking a particular script function. 236 237"identical" - this method compares two script objects for reference 238equality. It is a == Java comparison 239 240"dumpCounters" - will dump the debug counters' current values to 241stdout. 242 243Currently we count number of ScriptObjects in the system, number of 244Scope objects in the system, number of ScriptObject listeners added, 245removed and dead (without references). 246 247We also count number of ScriptFunctions, ScriptFunction invocations 248and ScriptFunction allocations. 249 250Furthermore we count PropertyMap statistics: how many property maps 251exist, how many times were property maps cloned, how many times did 252the property map history cache hit, prevent new allocations, how many 253prototype invalidations were done, how many time the property map 254proto cache hit. 255 256Finally we count callsite misses on a per callsite bases, which occur 257when a callsite has to be relinked, due to a previous assumption of 258object layout being invalidated. 259 260 261SYSTEM PROPERTY: nashorn.methodhandles.debug, 262nashorn.methodhandles.debug=create 263 264If this property is enabled, each MethodHandle related call that uses 265the java.lang.invoke package gets its MethodHandle intercepted and an 266instrumentation printout of arguments and return value appended to 267it. This shows exactly which method handles are executed and from 268where. (Also MethodTypes and SwitchPoints). This can be augmented with 269more information, for example, instance count, by subclassing or 270further extending the TraceMethodHandleFactory implementation in 271MethodHandleFactory.java. 272 273If the property is specialized with "=create" as its option, 274instrumentation will be shown for method handles upon creation time 275rather than at runtime usage. 276 277 278SYSTEM PROPERTY: nashorn.methodhandles.debug.stacktrace 279 280This does the same as nashorn.methodhandles.debug, but when enabled 281also dumps the stack trace for every instrumented method handle 282operation. Warning: This is enormously verbose, but provides a pretty 283decent "grep:able" picture of where the calls are coming from. 284 285See the description of the codegen logger below for a more verbose 286description of this option 287 288 289SYSTEM PROPERTY: nashorn.scriptfunction.specialization.disable 290 291There are several "fast path" implementations of constructors and 292functions in the NativeObject classes that, in their original form, 293take a variable amount of arguments. Said functions are also declared 294to take Object parameters in their original form, as this is what the 295JavaScript specification mandates. 296 297However, we often know quite a lot more at a callsite of one of these 298functions. For example, Math.min is called with a fixed number (2) of 299integer arguments. The overhead of boxing these ints to Objects and 300folding them into an Object array for the generic varargs Math.min 301function is an order of magnitude slower than calling a specialized 302implementation of Math.min that takes two integers. Specialized 303functions and constructors are identified by the tag 304@SpecializedFunction and @SpecializedConstructor in the Nashorn 305code. The linker will link in the most appropriate (narrowest types, 306right number of types and least number of arguments) specialization if 307specializations are available. 308 309Every ScriptFunction may carry specializations that the linker can 310choose from. This framework will likely be extended for user defined 311functions. The compiler can often infer enough parameter type info 312from callsites for in order to generate simpler versions with less 313generic Object types. This feature depends on future lazy jitting, as 314there tend to be many calls to user defined functions, some where the 315callsite can be specialized, some where we mostly see object 316parameters even at the callsite. 317 318If this system property is set to true, the linker will not attempt to 319use any specialized function or constructor for native objects, but 320just call the generic one. 321 322 323SYSTEM PROPERTY: nashorn.tcs.miss.samplePercent=<x> 324 325When running with the trace callsite option (-tcs), Nashorn will count 326and instrument any callsite misses that require relinking. As the 327number of relinks is large and usually produces a lot of output, this 328system property can be used to constrain the percentage of misses that 329should be logged. Typically this is set to 1 or 5 (percent). 1% is the 330default value. 331 332 333SYSTEM_PROPERTY: nashorn.profilefile=<filename> 334 335When running with the profile callsite options (-pcs), Nashorn will 336dump profiling data for all callsites to stderr as a shutdown hook. To 337instead redirect this to a file, specify the path to the file using 338this system property. 339 340 341=============== 3422. The loggers. 343=============== 344 345The Nashorn loggers can be used to print per-module or per-subsystem 346debug information with different levels of verbosity. The loggers for 347a given subsystem are available are enabled by using 348 349--log=<systemname>[:<level>] 350 351on the command line. 352 353Here <systemname> identifies the name of the subsystem to be logged 354and the optional colon and level argument is a standard 355java.util.logging.Level name (severe, warning, info, config, fine, 356finer, finest). If the level is left out for a particular subsystem, 357it defaults to "info". Any log message logged as the level or a level 358that is more important will be output to stderr by the logger. 359 360Several loggers can be enabled by a single command line option, by 361putting a comma after each subsystem/level tuple (or each subsystem if 362level is unspecified). The --log option can also be given multiple 363times on the same command line, with the same effect. 364 365For example: --log=codegen,fields:finest is equivalent to 366--log=codegen:info --log=fields:finest 367 368The subsystems that currently support logging are: 369 370 371* compiler 372 373The compiler is in charge of turning source code and function nodes 374into byte code, and installs the classes into a class loader 375controlled from the Context. Log messages are, for example, about 376things like new compile units being allocated. The compiler has global 377settings that all the tiers of codegen (e.g. Lower and CodeGenerator) 378use. 379 380 381* codegen 382 383The code generator is the emitter stage of the code pipeline, and 384turns the lowest tier of a FunctionNode into bytecode. Codegen logging 385shows byte codes as they are being emitted, line number information 386and jumps. It also shows the contents of the bytecode stack prior to 387each instruction being emitted. This is a good debugging aid. For 388example: 389 390[codegen] #41 line:2 (f)_afc824e 391[codegen] #42 load symbol x slot=2 392[codegen] #43 {1:O} load int 0 393[codegen] #44 {2:I O} dynamic_runtime_call GT:ZOI_I args=2 returnType=boolean 394[codegen] #45 signature (Ljava/lang/Object;I)Z 395[codegen] #46 {1:Z} ifeq ternary_false_5402fe28 396[codegen] #47 load symbol x slot=2 397[codegen] #48 {1:O} goto ternary_exit_107c1f2f 398[codegen] #49 ternary_false_5402fe28 399[codegen] #50 load symbol x slot=2 400[codegen] #51 {1:O} convert object -> double 401[codegen] #52 {1:D} neg 402[codegen] #53 {1:D} convert double -> object 403[codegen] #54 {1:O} ternary_exit_107c1f2f 404[codegen] #55 {1:O} return object 405 406shows a ternary node being generated for the sequence "return x > 0 ? 407x : -x" 408 409The first number on the log line is a unique monotonically increasing 410emission id per bytecode. There is no guarantee this is the same id 411between runs. depending on non deterministic code 412execution/compilation, but for small applications it usually is. If 413the system variable -Dnashorn.codegen.debug.trace=<x> is set, where x 414is a bytecode emission id, a stack trace will be shown as the 415particular bytecode is about to be emitted. This can be a quick way to 416determine where it comes from without attaching the debugger. "Who 417generated that neg?" 418 419The --log=codegen option is equivalent to setting the system variable 420"nashorn.codegen.debug" to true. 421 422 423* lower 424 425The lowering annotates a FunctionNode with symbols for each identifier 426and transforms high level constructs into lower level ones, that the 427CodeGenerator consumes. 428 429Lower logging typically outputs things like post pass actions, 430insertions of casts because symbol types have been changed and type 431specialization information. Currently very little info is generated by 432this logger. This will probably change. 433 434 435* access 436 437The --log=access option is equivalent to setting the system variable 438"nashorn.callsiteaccess.debug" to true. There are several levels of 439the access logger, usually the default level "info" is enough 440 441It is very simple to create your own logger. Use the DebugLogger class 442and give the subsystem name as a constructor argument. 443 444 445* fields 446 447The --log=fields option (at info level) is equivalent to setting the 448system variable "nashorn.fields.debug" to true. At the info level it 449will only show info about type assumptions that were invalidated. If 450the level is set to finest, it will also trace every AccessorProperty 451getter and setter in the program, show arguments, return values 452etc. It will also show the internal representation of respective field 453(Object in the normal case, unless running with the dual field 454representation)