|
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 |
|
17 SYSTEM PROPERTY: -Dnashorn.callsiteaccess.debug |
|
18 |
|
19 See the description of the access logger below. This flag is |
|
20 equivalent to enabling the access logger with "info" level. |
|
21 |
|
22 |
|
23 SYSTEM PROPERTY: -Dnashorn.compiler.ints.disable |
|
24 |
|
25 This flag prevents ints and longs (non double values) from being used |
|
26 for any primitive representation in the lowered IR. This is default |
|
27 false, i.e Lower will attempt to use integer variables as long as it |
|
28 can. For example, var x = 17 would try to use x as an integer, unless |
|
29 other operations occur later that require coercion to wider type, for |
|
30 example x *= 17.1; |
|
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 |
|
184 When this property is set, creation and manipulation of any symbol |
|
185 named "x" will show information about when the compiler changes its |
|
186 type assumption, bytecode local variable slot assignment and other |
|
187 data. This is useful if, for example, a symbol shows up as an Object, |
|
188 when you believe it should be a primitive. Usually there is an |
|
189 explanation for this, for example that it exists in the global scope |
|
190 and type analysis has to be more conservative. In that case, the stack |
|
191 trace upon type change to object will usually tell us why. |
|
192 |
|
193 |
|
194 SYSTEM PROPERTY: nashorn.lexer.xmlliterals |
|
195 |
|
196 If this property it set, it means that the Lexer should attempt to |
|
197 parse XML literals, which would otherwise generate syntax |
|
198 errors. Warning: there are currently no unit tests for this |
|
199 functionality. |
|
200 |
|
201 XML literals, when this is enabled, end up as standard LiteralNodes in |
|
202 the IR. |
|
203 |
|
204 |
|
205 SYSTEM_PROPERTY: nashorn.debug |
|
206 |
|
207 If this property is set to true, Nashorn runs in Debug mode. Debug |
|
208 mode is slightly slower, as for example statistics counters are enabled |
|
209 during the run. Debug mode makes available a NativeDebug instance |
|
210 called "Debug" in the global space that can be used to print property |
|
211 maps and layout for script objects, as well as a "dumpCounters" method |
|
212 that will print the current values of the previously mentioned stats |
|
213 counters. |
|
214 |
|
215 These functions currently exists for Debug: |
|
216 |
|
217 "map" - print(Debug.map(x)) will dump the PropertyMap for object x to |
|
218 stdout (currently there also exist functions called "embedX", where X |
|
219 is a value from 0 to 3, that will dump the contents of the embed pool |
|
220 for the first spill properties in any script object and "spill", that |
|
221 will dump the contents of the growing spill pool of spill properties |
|
222 in any script object. This is of course subject to change without |
|
223 notice, should we change the script object layout. |
|
224 |
|
225 "methodHandle" - this method returns the method handle that is used |
|
226 for invoking a particular script function. |
|
227 |
|
228 "identical" - this method compares two script objects for reference |
|
229 equality. It is a == Java comparison |
|
230 |
|
231 "dumpCounters" - will dump the debug counters' current values to |
|
232 stdout. |
|
233 |
|
234 Currently we count number of ScriptObjects in the system, number of |
|
235 Scope objects in the system, number of ScriptObject listeners added, |
|
236 removed and dead (without references). |
|
237 |
|
238 We also count number of ScriptFunctions, ScriptFunction invocations |
|
239 and ScriptFunction allocations. |
|
240 |
|
241 Furthermore we count PropertyMap statistics: how many property maps |
|
242 exist, how many times were property maps cloned, how many times did |
|
243 the property map history cache hit, prevent new allocations, how many |
|
244 prototype invalidations were done, how many time the property map |
|
245 proto cache hit. |
|
246 |
|
247 Finally we count callsite misses on a per callsite bases, which occur |
|
248 when a callsite has to be relinked, due to a previous assumption of |
|
249 object layout being invalidated. |
|
250 |
|
251 |
|
252 SYSTEM PROPERTY: nashorn.methodhandles.debug, |
|
253 nashorn.methodhandles.debug=create |
|
254 |
|
255 If this property is enabled, each MethodHandle related call that uses |
|
256 the java.lang.invoke package gets its MethodHandle intercepted and an |
|
257 instrumentation printout of arguments and return value appended to |
|
258 it. This shows exactly which method handles are executed and from |
|
259 where. (Also MethodTypes and SwitchPoints). This can be augmented with |
|
260 more information, for example, instance count, by subclassing or |
|
261 further extending the TraceMethodHandleFactory implementation in |
|
262 MethodHandleFactory.java. |
|
263 |
|
264 If the property is specialized with "=create" as its option, |
|
265 instrumentation will be shown for method handles upon creation time |
|
266 rather than at runtime usage. |
|
267 |
|
268 |
|
269 SYSTEM PROPERTY: nashorn.methodhandles.debug.stacktrace |
|
270 |
|
271 This does the same as nashorn.methodhandles.debug, but when enabled |
|
272 also dumps the stack trace for every instrumented method handle |
|
273 operation. Warning: This is enormously verbose, but provides a pretty |
|
274 decent "grep:able" picture of where the calls are coming from. |
|
275 |
|
276 See the description of the codegen logger below for a more verbose |
|
277 description of this option |
|
278 |
|
279 |
|
280 SYSTEM PROPERTY: nashorn.scriptfunction.specialization.disable |
|
281 |
|
282 There are several "fast path" implementations of constructors and |
|
283 functions in the NativeObject classes that, in their original form, |
|
284 take a variable amount of arguments. Said functions are also declared |
|
285 to take Object parameters in their original form, as this is what the |
|
286 JavaScript specification mandates. |
|
287 |
|
288 However, we often know quite a lot more at a callsite of one of these |
|
289 functions. For example, Math.min is called with a fixed number (2) of |
|
290 integer arguments. The overhead of boxing these ints to Objects and |
|
291 folding them into an Object array for the generic varargs Math.min |
|
292 function is an order of magnitude slower than calling a specialized |
|
293 implementation of Math.min that takes two integers. Specialized |
|
294 functions and constructors are identified by the tag |
|
295 @SpecializedFunction and @SpecializedConstructor in the Nashorn |
|
296 code. The linker will link in the most appropriate (narrowest types, |
|
297 right number of types and least number of arguments) specialization if |
|
298 specializations are available. |
|
299 |
|
300 Every ScriptFunction may carry specializations that the linker can |
|
301 choose from. This framework will likely be extended for user defined |
|
302 functions. The compiler can often infer enough parameter type info |
|
303 from callsites for in order to generate simpler versions with less |
|
304 generic Object types. This feature depends on future lazy jitting, as |
|
305 there tend to be many calls to user defined functions, some where the |
|
306 callsite can be specialized, some where we mostly see object |
|
307 parameters even at the callsite. |
|
308 |
|
309 If this system property is set to true, the linker will not attempt to |
|
310 use any specialized function or constructor for native objects, but |
|
311 just call the generic one. |
|
312 |
|
313 |
|
314 SYSTEM PROPERTY: nashorn.tcs.miss.samplePercent=<x> |
|
315 |
|
316 When running with the trace callsite option (-tcs), Nashorn will count |
|
317 and instrument any callsite misses that require relinking. As the |
|
318 number of relinks is large and usually produces a lot of output, this |
|
319 system property can be used to constrain the percentage of misses that |
|
320 should be logged. Typically this is set to 1 or 5 (percent). 1% is the |
|
321 default value. |
|
322 |
|
323 |
|
324 SYSTEM_PROPERTY: nashorn.profilefile=<filename> |
|
325 |
|
326 When running with the profile callsite options (-pcs), Nashorn will |
|
327 dump profiling data for all callsites to stderr as a shutdown hook. To |
|
328 instead redirect this to a file, specify the path to the file using |
|
329 this system property. |
|
330 |
|
331 |
|
332 =============== |
|
333 2. The loggers. |
|
334 =============== |
|
335 |
|
336 The Nashorn loggers can be used to print per-module or per-subsystem |
|
337 debug information with different levels of verbosity. The loggers for |
|
338 a given subsystem are available are enabled by using |
|
339 |
|
340 --log=<systemname>[:<level>] |
|
341 |
|
342 on the command line. |
|
343 |
|
344 Here <systemname> identifies the name of the subsystem to be logged |
|
345 and the optional colon and level argument is a standard |
|
346 java.util.logging.Level name (severe, warning, info, config, fine, |
|
347 finer, finest). If the level is left out for a particular subsystem, |
|
348 it defaults to "info". Any log message logged as the level or a level |
|
349 that is more important will be output to stderr by the logger. |
|
350 |
|
351 Several loggers can be enabled by a single command line option, by |
|
352 putting a comma after each subsystem/level tuple (or each subsystem if |
|
353 level is unspecified). The --log option can also be given multiple |
|
354 times on the same command line, with the same effect. |
|
355 |
|
356 For example: --log=codegen,fields:finest is equivalent to |
|
357 --log=codegen:info --log=fields:finest |
|
358 |
|
359 The subsystems that currently support logging are: |
|
360 |
|
361 |
|
362 * compiler |
|
363 |
|
364 The compiler is in charge of turning source code and function nodes |
|
365 into byte code, and installs the classes into a class loader |
|
366 controlled from the Context. Log messages are, for example, about |
|
367 things like new compile units being allocated. The compiler has global |
|
368 settings that all the tiers of codegen (e.g. Lower and CodeGenerator) |
|
369 use. |
|
370 |
|
371 |
|
372 * codegen |
|
373 |
|
374 The code generator is the emitter stage of the code pipeline, and |
|
375 turns the lowest tier of a FunctionNode into bytecode. Codegen logging |
|
376 shows byte codes as they are being emitted, line number information |
|
377 and jumps. It also shows the contents of the bytecode stack prior to |
|
378 each instruction being emitted. This is a good debugging aid. For |
|
379 example: |
|
380 |
|
381 [codegen] #41 line:2 (f)_afc824e |
|
382 [codegen] #42 load symbol x slot=2 |
|
383 [codegen] #43 {1:O} load int 0 |
|
384 [codegen] #44 {2:I O} dynamic_runtime_call GT:ZOI_I args=2 returnType=boolean |
|
385 [codegen] #45 signature (Ljava/lang/Object;I)Z |
|
386 [codegen] #46 {1:Z} ifeq ternary_false_5402fe28 |
|
387 [codegen] #47 load symbol x slot=2 |
|
388 [codegen] #48 {1:O} goto ternary_exit_107c1f2f |
|
389 [codegen] #49 ternary_false_5402fe28 |
|
390 [codegen] #50 load symbol x slot=2 |
|
391 [codegen] #51 {1:O} convert object -> double |
|
392 [codegen] #52 {1:D} neg |
|
393 [codegen] #53 {1:D} convert double -> object |
|
394 [codegen] #54 {1:O} ternary_exit_107c1f2f |
|
395 [codegen] #55 {1:O} return object |
|
396 |
|
397 shows a ternary node being generated for the sequence "return x > 0 ? |
|
398 x : -x" |
|
399 |
|
400 The first number on the log line is a unique monotonically increasing |
|
401 emission id per bytecode. There is no guarantee this is the same id |
|
402 between runs. depending on non deterministic code |
|
403 execution/compilation, but for small applications it usually is. If |
|
404 the system variable -Dnashorn.codegen.debug.trace=<x> is set, where x |
|
405 is a bytecode emission id, a stack trace will be shown as the |
|
406 particular bytecode is about to be emitted. This can be a quick way to |
|
407 determine where it comes from without attaching the debugger. "Who |
|
408 generated that neg?" |
|
409 |
|
410 The --log=codegen option is equivalent to setting the system variable |
|
411 "nashorn.codegen.debug" to true. |
|
412 |
|
413 |
|
414 * lower |
|
415 |
|
416 The lowering annotates a FunctionNode with symbols for each identifier |
|
417 and transforms high level constructs into lower level ones, that the |
|
418 CodeGenerator consumes. |
|
419 |
|
420 Lower logging typically outputs things like post pass actions, |
|
421 insertions of casts because symbol types have been changed and type |
|
422 specialization information. Currently very little info is generated by |
|
423 this logger. This will probably change. |
|
424 |
|
425 |
|
426 * access |
|
427 |
|
428 The --log=access option is equivalent to setting the system variable |
|
429 "nashorn.callsiteaccess.debug" to true. There are several levels of |
|
430 the access logger, usually the default level "info" is enough |
|
431 |
|
432 It is very simple to create your own logger. Use the DebugLogger class |
|
433 and give the subsystem name as a constructor argument. |
|
434 |
|
435 |
|
436 * fields |
|
437 |
|
438 The --log=fields option (at info level) is equivalent to setting the |
|
439 system variable "nashorn.fields.debug" to true. At the info level it |
|
440 will only show info about type assumptions that were invalidated. If |
|
441 the level is set to finest, it will also trace every AccessorProperty |
|
442 getter and setter in the program, show arguments, return values |
|
443 etc. It will also show the internal representation of respective field |
|
444 (Object in the normal case, unless running with the dual field |
|
445 representation) |