WJUG 114. [MID PL] Warsztaty: Java Flight Recorder i JMC - Michał Weyer i Jakub Słota - Notatki

notatki.md

Wrocław JUG, 8.11.2018

Wstep

Profilery:

• Samplujące - próbki o zadanej częstotliwości - dane mogą nie być widoczne - szybksze
• Instrumentujące - wpinają się w kod i odkładają dane - wolniejsze

JFR

JFR jest w java od dawna, w jrockicie, potem wciagneli do openjdk

Licencja:

• od java 11 za darmo
• poprzednio za wieksze pieniadze do debugowania produkcji
• na dev zawsze za darmo

Nowe UI w java 11

JFR zrzuca surowe eventy do pliku i UI renderuje te eventy

Działanie

Eventy sa zapisywane optymalnie:

1. w buforach cyklicznych per watek, zeby uniknac synchronizacji
2. potem mergeowane do jednego bufora i zrzucane do pliku
3. narzut ok 1-2%

• Uwaga na opcje monitorowania pamieci, mozna lrzegladac sterte ale ona robi inspekcje i uruchamia GC.
• Domyslnie writeouw io nie zobaczymy bo jest treshod ustawic file read na 0
• Nie wiadomo w rzeczywitości jak dobrać paramery próbkowania, trzeba uruchmić i sprawdzić, czy nam wystarczają takie informacje.

Obsługa UI

Na roznych ekranach mozna zaznaczac dane i prawym prziciskiem myszy i dodac do zakresu widocznosci i focus. To pozwala na ograniczenie innych perspektyw i samej listy eventow.

Widoczne sa w ui:

• env vars
• parametry uruchomieniowe, classpath
• inne procesy i uzycie cpu na tle calej maszyny
• parametry recordingu - WAZNE

Widok Method Profiling

• nie widac metod tylko pakiey, wiec Window -> Show View -> Stacktrace

Widok Lock instance

Lock instance sa gruboziarniste, tu sa tyko monitory. Wiec nie bedzie malych lockow a instrumentowac tego nie bedziemy bo to juz nie bezie szybkie.

Można zaznaczyć monitor, potem konkretny obiekt, prawym p myszy -> add to filter and focus -> mamy przefiltrowane wątki w wiodku wątków.

Widok Threads

Można ogólnie sprawdzić synchronizację wątków, czy na czymś wspólnym nie wiszą.

Uruchamianie

3 sposoby na nagranie:

1. przy uruchomieniu
2. przez jmc
3. przez cli

Uruchomienie z parametru:

-XX:+UnlockDiagnosticVMOptions 
-XX:+DebugNonSafepoints 
-XX:+UnlockCommercialFeatures 
-XX:+FlightRecorder 
-XX:StartFlightRecording=duration=180s,filename=eclipse-startup-detailed-default.jfr,settings=E:\tmp\JFR-lab\input\profile-maximum.jfc

Gdzie plik profile-maximum.jfc można wygenerować sobie z UI wybierając template, duplikat i eksport.

Z cli jak proces już działa

Np. wysyłamy adminom instrukjcę.

jcmd PID JFR.check
jcmd PID JFR.start maxsize=50M name=recording1

jcmd PID JFR.dump filename=dump.jfr

jcmd PID JFR.stop name=recording1

Ćwiczenia

Cwiczenie 2.

Dlaczego tak malo sampli?

• czestotliwosc profilera? co 10s
• processes - 2 powod procesy na niebiesko - przestaly chodzic w pewnym momencie
• threaddumps - 1 powod watki wisza i nic nie robia, wiec nie ma co zapisywac

Cwiczenie 3.

• dlaczego wiecej gc dla detailed? bo jest GC LOcker Initiated, jak prawdzamy gc to od musi go odpalic (memory profiling, all, including heap statistics)

• dlaczego nie ma wpisow w pamieci? (bo nie jest zaznaczony TLAB w recording)

Customowe eventy

package jfr.customevents;

import jdk.jfr.Category;
import jdk.jfr.DataAmount;
import jdk.jfr.Description;
import jdk.jfr.Event;
import jdk.jfr.Frequency;
import jdk.jfr.Label;
import jdk.jfr.Name;
import jdk.jfr.StackTrace;

@Category("my category")
@Label("Custom made event")
@Description("my event description")
@StackTrace()
@Name("customEvent")
public class CustomEvent extends Event {

	@Label("Content")
	@Description("Describes event")
	private String displayName;

	@Label("Data amount")
	@Description("Amount stored")
	@DataAmount
	private int memoryAmountBytes;

	@Label("Frequency")
	@Description("Meaured frequency")
	@Frequency
	private int frequencyHz;
	
	public void setDisplayName(String string) {
		displayName = string;
	}

	public void reset() {
		displayName = "";
		frequencyHz = 0;
		memoryAmountBytes = 0;
	}

	public void setFrequencyHz(int i) {
		this.frequencyHz = i;
	}

	public void setMemoryAmountBytes(int i) {
		this.memoryAmountBytes = i;
	}

}

package jfr.customevents;

import java.io.IOException;
import java.nio.file.Path;
import java.nio.file.Paths;
import java.time.Duration;

import jdk.jfr.Recording;
import jdk.jfr.consumer.RecordingFile;

/**
 * See: http://hirt.se/blog/?p=870&utm_content=buffer0663a&utm_medium=social&utm_source=twitter.com&utm_campaign=buffer
 */
public class RunRecording {
	public static void main(String[] args) throws IOException {

		Path path = Paths.get(System.getProperty("user.dir"), "myRecording.jfr");

		try (Recording recording = new Recording()) {
			recording.setName("Custom Recording");
//			recording.enable("jdk.SystemProcess").withPeriod(Duration.ofSeconds(1));
			recording.start();
			CustomEvent event = new CustomEvent();
			for (int n = 0; n < 50; n++) {
				event.reset();
				event.begin();
				event.setDisplayName("Event nbr - " + n) ;
				event.setFrequencyHz(25);
				event.setMemoryAmountBytes(25);
				event.commit();
				try {
					Thread.sleep(100);
				} catch (InterruptedException e) {
					e.printStackTrace();
				}
			}

			recording.stop();
			recording.dump(path);
//			recording. // CO TUTAJ ???


			for (var eventRead : RecordingFile.readAllEvents(path)) {
//				if (!eventRead.getEventType().getName().equals("customEvent")) {
//					continue;
//				}

				String description = eventRead.getValue("displayName");
				System.out.printf("displayName: %s (time: %dns)\n", description, eventRead.getDuration().getNano());
				System.out.println(eventRead.getStackTrace() != null ? "stackTrace stored" : "stackTrace unavailable");
			}
		}
	}
}