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