The Talon Manual

Versions Compared

Old Version 23

changes.mady.by.user Unknown User (colin)

Saved on

compared with

New Version 24

changes.mady.by.user Girish Mutreja

Saved on

Key

  • This line was added.
  • This line was removed.
  • Formatting was changed.

...

When heartbeats are enabled they can be consumed or emitted in several ways, discussed below.

Heartbeat Tracing

...

By default all server statistics tracers are disabled as trace logging is not zero garbage and introduces cpu overhead in computing statistics. While tracing heartbeats isn't recommended in production, enabling server statistics trace output can be useful for debugging and performance tuning. To enable you will need to configure the appropriate tracers at the debug level. See the Output Trace Loggers section for more detail.

Code Block
languagexml
<xvms>
  <xvmname="my-xvm">
    <heartbeats enabled="true" interval="5">
      <logging enabled="true"></logging>
      <tracing enabled="true"></tracing>
    </heartbeats>
  </xvm>
</xvms>

...

Heartbeat Logging

Applications that are latency sensitive might prefer to leave all tracers disabled to avoid unnecessary allocations and the associated GC activity. As an alternative, it's possible to enable logging of zero-garbage heartbeat messages to a binary transaction log:

...

When a storeRoot is not set, an xvm XVM will log heartbeats to {XRuntime.getDataDirectory}/server-heartbeats/<xvm-name>-heartbeats.log, which can then be queried and traced from a separate process using the Stats Dump Tool.

...

  • DDL Reference for more options that can be used to configure heartbeat logging. 

 

Heartbeat Event Handlers

Your application can register an event handler for server heartbeats to handle them in process. 

...

A Lumino or Robin controller can also be used to connect to a server via a direct admin connection over TCP to listen for heartbeats for monitoring purposes. The XVMs stats thread will queue copies of each emitted heartbeats to each connected admin client. 

Anchor
_Toc221568564
_Toc221568564
Heartbeat Trace Output

When heartbeat tracing is enabled heartbeat Heartbeat trace is emitted to the nv.server.heartbeat logger at a level of info. This section discussed the output format of heartbeats INFO. Trace is only emitted for the types of heartbeat trace for which tracing has been enabled. This section discusses the various types of heartbeat trace, how the trace for those types is enabled and an explanation on the trace output for each of the types. 

(info) See Also: 

System Stats

Appears in trace output when nv.server.stats.enable=true and nv.server.stats.sys.trace=debug

Code Block
xml
xml
<xvms>
  <xvm name="my-xvm">
    <heartbeats enabled="true" interval="5">
      <tracing enabled="true">
        <traceSysStats>true</traceSysStats>
      </tracing>
    </heartbeats>
  </xvm>
</xvms>

Trace Output

div
stylefont-size: smaller
No Format
[System Stats]
Sat May 13 12:14:03 PDT 2017 'market' server (pid=54449) 2 apps (collection time=0 ns)
System: 20 processors, load average: 0.73 (load 0.10 process, 0.10 total system)
Memory (system): 94.4G total, 89.8G free, 5.5G committed (Swap: 96.6G total, 96.6G free)
Memory (proc): HEAP 1.5G init, 522M used, 1.5G commit, 1.5G max NON-HEAP 2M init, 47M used, 48M commit, 0K max
Disk:
  [/ Total: 49.2GB, Usable:  18GB, Free:  18GB]
  [/dev/shm Total: 47.2GB, Usable: 47.2GB, Free: 47.2GB]
  [/boot Total: 484.2MB, Usable: 422.4MB, Free: 422.4MB]
  [/home Total: 405.2GB, Usable: 267GB, Free: 267GB]
  [/distributions Total: 196.9GB, Usable: 8.1GB, Free: 8.1GB]
Threads: 20 total (16 daemon) 21 peak
JIT: HotSpot 64-Bit Tiered Compilers, time: 2959 ms
GC:
...ParNew [0 collections, commulative time: 0 ms]
...MarkSweepCompact [1 collections, commulative time: 54 ms]

...

Code Block
xml
xml
<xvms>
  <xvm name="my-xvm">
    <heartbeats enabled="true" interval="5">
      <collectIndividualThreadStats>true</collectIndividualThreadStats>
      <tracing enabled="true">
        <traceThreadStats>true</traceThreadStats>
      </tracing>
    </heartbeats>
  </xvm>
</xvms>

...

Trace Output

div
stylefont-size: smaller
No Format
[Thread Stats]
ID    CPU       DCPU    DUSER   CPU%  USER% WAIT% STATE           NAME
1     6.0s      982.8us 0       1     0     0     RUNNABLE        X-Server-blackbird1-Main (aff=[])
2     9.3ms     0       0       0     0     0     WAITING         Reference Handler
3     8.7ms     0       0       0     0     0     WAITING         Finalizer
4     43.8us    0       0       0     0     0     RUNNABLE        Signal Dispatcher
23    53.9ms    722.7us 0       1     0     0     RUNNABLE        X-EDP-McastReceiver (aff=[1(s0c1t0)])
24    26.3ms    426.5us 0       1     0     0     TIMED_WAITING   X-EDP-Timer (aff=[1(s0c1t0)])
26    1.9s      33.9ms  30.0ms  1     1     0     RUNNABLE        X-Server-blackbird1-StatsRunner (aff=[1(s0c1t0)])
28    6.9m      10.2s   4.8s    100   48    0     RUNNABLE        X-Server-blackbird1-IOThread-1 (aff=[8(s0c11t0)])
30    236.6us   0       0       0     0     0     TIMED_WAITING   X-EventMultiplexer-Wakeup-admin (aff=[1(s0c1t0)])
34    685.4ms   11.5ms  0       1     0     0     TIMED_WAITING   X-EventMultiplexer-Wakeup-blackbird (aff=[1(s0c1t0)])
35    9.2m      10.3s   10.3s   100   100   100   RUNNABLE        X-ODS-StoreLog-blackbird-1 (aff=[4(s0c4t0)])
40    9.2m      10.3s   10.3s   100   100   0     RUNNABLE        SorProcessor (aff=[5(s0c8t0)])
41    11.7ms    0       0       0     0     100   WAITING         X-STEMux-admin-1 (aff=[])
42    9.0m      10.3s   10.2s   100   99    90    RUNNABLE        X-STEMux-blackbird-2 (aff=[2(s0c2t0)])
43    7.0m      10.2s   4.8s    100   47    0     RUNNABLE        X-ODS-StoreReplicatorLinkReader-myapp-93323c0d-5e4c-48d7-8cd4-f251963a6310 (aff=[3(s0c3t0)])
44    52.0ms    973.7us 0       1     0     0     RUNNABLE        X-ODS-StoreLinkAcceptor-1 (aff=[1(s0c1t0)])
45    58.9ms    1.0ms   0       1     0     0     RUNNABLE        X-EDP-McastReceiver (aff=[1(s0c1t0)])
46    41.9ms    592.2us 0       1     0     0     TIMED_WAITING   X-EDP-Timer (aff=[1(s0c1t0)])
48    9.1m      10.3s   10.1s   100   98    98    RUNNABLE        X-AEP-BusManager-IO-blackbird.market (aff=[7(s0c10t0)])
49    1.1s      0       0       0     0     0     RUNNABLE        X-Client-LinkManagerReader[c43b3977-572f-4366-8524-f17678e71515] (aff=[9(s0c12t0)])
50    9.1m      10.3s   10.3s   100   100   93    RUNNABLE        X-AEP-BusManager-IO-blackbird.blackbird (aff=[6(s0c9t0)])

...

  • A miss has been recorded for the pool in a given interval and it results in a new object being allocated. 
  • The number of preallocated obects taken from a pool drops below the configured value for the pool depletion threshold.

Trace Output

div
stylefont-size: smaller
No Format
[Pool Stats]
PUT   DPUT  GET   DGET  HIT   DHIT  MISS  DMISS GROW  DGROW EVIC  DEVIC DWSH  DDWSH SIZE  PRE   CAP   NAME
38    0     16.8M 0     38    0     16.8M 0     0     0     0     0     0     0     0     0     1024  iobuf.native-32.20
1     0     62    0     1     0     61    0     0     0     0     0     0     0     0     0     1024  iobuf.native-64.21
1     0     1.0M  0     1     0     1.0M  0     0     0     0     0     0     0     0     0     1024  iobuf.native-256.23
7     0     75    0     7     0     68    0     0     0     0     0     0     0     0     0     1024  iobuf.heap-32.1

...

Code Block
xml
xml
<xvms>
  <xvm name="my-xvm">
    <heartbeats enabled="true" interval="5">
      <tracing enabled="true">
        <traceUserStats>true</traceUserStats>
      </tracing>
    </heartbeats>
  </xvm>
</xvms>

Trace Output

div
stylefont-size: 10px;
No Format
[App (ems) User Stats]
...Gauges{
......EMS Messages Received: 142604
......EMS Orders Received: 35651
...}
...Series{
......[In Proc Tick To Trade(sno=35651, #points=150, #skipped=0)
.........In Proc Tick To Trade(interval): [sample=150, min=72 max=84 mean=75 median=75 75%ile=77 90%ile=79 99%ile=83 99.9%ile=84 99.99%ile=84]
.........In Proc Tick To Trade (running): [sample=35651, min=72 max=2000 mean=93 median=76 75%ile=82 90%ile=111 99%ile=227 99.9%ile=805 99.99%ile=1197]
......[In Proc Time To First Slice(sno=35651, #points=150, #skipped=0)
.........In Proc Time To First Slice(interval): [sample=150, min=85 max=98 mean=88 median=88 75%ile=90 90%ile=92 99%ile=95 99.9%ile=98 99.99%ile=98]
.........In Proc Time To First Slice (running): [sample=35651, min=84 max=4469 mean=249 median=88 75%ile=95 90%ile=133 99%ile=283 99.9%ile=3628 99.99%ile=4143]
...}

...

Code Block
xml
xml
<xvms>
  <xvm name="my-xvm">
    <heartbeats enabled="true" interval="5">
      <tracing enabled="true">
        <traceAppStats>true</traceAppStats>
      </tracing>
    </heartbeats>
  </xvm>
</xvms>

Trace Output

The trace output

(info) See Also: 

...