Aeron Agent¶
Aeron Agent is a Java agent used to provide runtime, low level log information on what's happening in Aeron, Aeron Archive and Aeron Cluster. These logging statements range from higher level admin events to high volume data frame events.
The Aeron Agent log data can be especially useful when debugging Archive and Cluster issues.
Available logging options¶
Environment Variable | Options |
---|---|
aeron.event.log |
Comma separated list of DriverEventCodes , or admin for all admin events, or all for everything |
aeron.event.archive.log |
Comma separated list of ArchiveEventCodes , or all for everything |
aeron.event.cluster.log |
Comma separated list of ClusterEventCodes , or all for everything |
Additionally, you can log the output to file instead of the default std out by providing a value for aeron.event.log.filename
.
Attaching to a process on start¶
Attaching the Aeron Agent to a process on start is simple, as shown by this sample startup script from one of the Aeron Cookbook samples:
java --add-opens java.base/sun.nio.ch=ALL-UNNAMED \
-javaagent:/root/aeron/aeron-agent-1.42.0.jar \
-Djava.net.preferIPv4Stack=true \
-Daeron.event.log=admin \
-Daeron.event.archive.log=all \
-jar /root/jar/archive-backup-0.1-SNAPSHOT-all.jar
See GitHub for the full sample.
Dynamic Logging Agent¶
With the Dynamic Logging Agent added in Aeron 1.33.0+, the agent can be easily attached to a running process.
Steps:
- Before launching the Aeron process you want instrumented, you must define the events you are interested in capturing by letting aeron agent know what to capture either via environment variables or via
-D
arguments, such as-Daeron.event.log=admin
. See above for the available options. - With the process to instrument already running, get the PID
- Launch the
io.aeron.agent.DynamicLoggingAgent
with thestart
command.
Sample command line¶
To start logging in a process with PID 42945:
java -cp /path-to/aeron-all-1.42.0.jar io.aeron.agent.DynamicLoggingAgent /path-to/aeron-agent-1.42.0.jar 42945 start
Sample output¶
The value in the left most [
and ]
is the timestamp of the event, defined as the current timestamp in nanoseconds, divided by 1,000,000,000. This means that the value before the decimal is in seconds, so you can work out from the initial line item [76948.355606523] log started 2021-04-17 14:26:41.710-0400
that the event at [76958.678426732]
happened around 14:26:41.710 + 10.323s = 14:26:52.033
. The 10.323s
is the difference between 76948.355
and 76958.678
. The source of the data is System.nanoTime()
, which has no relation to wall time - it can only be used for relative times.
This is an example snippet from a cluster node (the RFQ sample), with aeron.event.log
set to all
.
[76948.355606523] log started 2021-04-17 14:26:41.710-0400
[76958.678426732] DRIVER: FRAME_IN [52/52]: 127.0.0.1:55443 SETUP 00000000 len 40 2073747220:101:905418016 905418016 @0 16777216 MTU 1408 TTL 0
[76958.685011759] DRIVER: CMD_OUT_AVAILABLE_IMAGE [147/147]: 2073747220:101 [57:48] [49] /var/folders/aeron-driver/images/49.logbuffer 127.0.0.1:55443
[76958.685099301] DRIVER: FRAME_OUT [48/48]: 127.0.0.1:55443 SM 00000000 len 36 2073747220:101:905418016 @0 131072 -4489607960779398291
[76958.686931252] DRIVER: FRAME_IN [44/44]: 127.0.0.1:55443 DATA 11000000 len 0 2073747220:101:905418016 @0
[76958.687164768] DRIVER: FRAME_IN [140/140]: 127.0.0.1:55443 DATA 11000000 len 98 2073747220:101:905418016 @0
[76958.694589747] DRIVER: CMD_IN_ADD_PUBLICATION [58/58]: 102 [7:50] aeron:udp?endpoint=localhost:57377
[76958.69499685] DRIVER: SEND_CHANNEL_CREATION [92/92]: UdpChannel - localData: 0.0.0.0/0.0.0.0:0, remoteData: localhost/127.0.0.1:57377, ttl: 0
[76958.697468817] DRIVER: CMD_OUT_PUBLICATION_READY [138/138]: -74825448:102 75 65 [50 50] /var/folders/aeron-driver/publications/50.logbuffer
[76958.697569264] DRIVER: FRAME_OUT [52/52]: 127.0.0.1:57377 SETUP 00000000 len 40 -74825448:102:728163187 728163187 @0 16777216 MTU 1408 TTL 0
[76958.758041065] DRIVER: FRAME_IN [48/48]: 127.0.0.1:57377 SM 00000000 len 36 -74825448:102:728163187 @0 131072 -985368778043801883
[76958.758666168] DRIVER: FRAME_OUT [44/44]: 127.0.0.1:57377 DATA 11000000 len 0 -74825448:102:728163187 @0
[76958.7652581] DRIVER: FRAME_OUT [108/108]: 127.0.0.1:57377 DATA 11000000 len 80 -74825448:102:728163187 @0
[76958.765445077] DRIVER: CMD_IN_ADD_PUBLICATION [58/58]: 102 [21:51] aeron:udp?endpoint=localhost:57377
[76958.765583608] DRIVER: CMD_OUT_PUBLICATION_READY [138/138]: -74825448:102 75 65 [51 50] /var/folders/aeron-driver/publications/50.logbuffer
[76958.773609799] DRIVER: FRAME_IN [108/108]: 127.0.0.1:55443 DATA 11000000 len 90 2073747220:101:905418016 @128
[76958.77373172] DRIVER: FRAME_IN [140/140]: 127.0.0.1:55443 DATA 11000000 len 102 2073747220:101:905418016 @224
[76958.775272352] DRIVER: FRAME_OUT [140/140]: 127.0.0.1:57377 DATA 11000000 len 118 -74825448:102:728163187 @96
[76958.777991182] DRIVER: FRAME_IN [108/108]: 127.0.0.1:55443 DATA 11000000 len 92 2073747220:101:905418016 @352
[76958.780923987] DRIVER: FRAME_OUT [140/140]: 127.0.0.1:57377 DATA 11000000 len 100 -74825448:102:728163187 @224
[76958.783483437] DRIVER: FRAME_IN [108/108]: 127.0.0.1:55443 DATA 11000000 len 88 2073747220:101:905418016 @448
[76958.786164552] DRIVER: FRAME_OUT [140/140]: 127.0.0.1:57377 DATA 11000000 len 104 -74825448:102:728163187 @352
[76958.788915601] DRIVER: FRAME_IN [76/76]: 127.0.0.1:55443 DATA 11000000 len 56 2073747220:101:905418016 @544
[76958.789200034] DRIVER: CMD_IN_REMOVE_PUBLICATION [24/24]: 50 [7:52]
[76958.789237205] DRIVER: CMD_OUT_ON_OPERATION_SUCCESS [8/8]: 52
[76958.790866084] DRIVER: CMD_IN_REMOVE_PUBLICATION [24/24]: 51 [21:53]
[76958.790904905] DRIVER: CMD_OUT_ON_OPERATION_SUCCESS [8/8]: 53
[76958.875888058] DRIVER: FRAME_OUT [48/48]: 127.0.0.1:55443 SM 00000000 len 36 2073747220:101:905418016 @0 131072 -4489607960779398291
[76958.886665327] DRIVER: FRAME_OUT [44/44]: 127.0.0.1:57377 DATA 11100000 len 0 -74825448:102:728163187 @480
[76958.987313678] DRIVER: FRAME_OUT [44/44]: 127.0.0.1:57377 DATA 11100000 len 0 -74825448:102:728163187 @480
[76959.076562784] DRIVER: FRAME_OUT [48/48]: 127.0.0.1:55443 SM 00000000 len 36 2073747220:101:905418016 @0 131072 -4489607960779398291
[76959.088009394] DRIVER: FRAME_OUT [44/44]: 127.0.0.1:57377 DATA 11100000 len 0 -74825448:102:728163187 @480
[76959.188642945] DRIVER: FRAME_OUT [44/44]: 127.0.0.1:57377 DATA 11100000 len 0 -74825448:102:728163187 @480