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