Mercurial > hg > release > thermostat-1.2
changeset 1577:bd5e7855f9f3
Get results if VM exits while profiling
Reviewed-by: jerboaa, vanaltj
Review-thread: http://icedtea.classpath.org/pipermail/thermostat/2014-November/011702.html
author | Omair Majid <omajid@redhat.com> |
---|---|
date | Fri, 28 Nov 2014 16:36:17 -0500 |
parents | a614e6dec69a |
children | 43864ae00dbf |
files | vm-profiler/agent/src/main/java/com/redhat/thermostat/vm/profiler/agent/internal/ProfileVmRequestReceiver.java vm-profiler/agent/src/test/java/com/redhat/thermostat/vm/profiler/agent/internal/ProfileVmRequestReceiverTest.java vm-profiler/jvm-agent/src/main/java/com/redhat/thermostat/vm/profiler/agent/jvm/InstrumentationControl.java vm-profiler/jvm-agent/src/test/java/com/redhat/thermostat/vm/profiler/agent/jvm/InstrumentationControlTest.java |
diffstat | 4 files changed, 401 insertions(+), 52 deletions(-) [+] |
line wrap: on
line diff
--- a/vm-profiler/agent/src/main/java/com/redhat/thermostat/vm/profiler/agent/internal/ProfileVmRequestReceiver.java Fri Nov 28 15:47:39 2014 -0500 +++ b/vm-profiler/agent/src/main/java/com/redhat/thermostat/vm/profiler/agent/internal/ProfileVmRequestReceiver.java Fri Nov 28 16:36:17 2014 -0500 @@ -36,12 +36,22 @@ package com.redhat.thermostat.vm.profiler.agent.internal; +import java.io.File; +import java.io.FilenameFilter; +import java.io.IOException; +import java.util.ArrayList; +import java.util.Arrays; +import java.util.Collections; +import java.util.Comparator; +import java.util.List; import java.util.concurrent.ConcurrentHashMap; import java.util.logging.Level; import java.util.logging.Logger; import com.redhat.thermostat.agent.VmStatusListener; import com.redhat.thermostat.agent.command.RequestReceiver; +import com.redhat.thermostat.common.Clock; +import com.redhat.thermostat.common.SystemClock; import com.redhat.thermostat.common.command.Request; import com.redhat.thermostat.common.command.Response; import com.redhat.thermostat.common.command.Response.ResponseType; @@ -53,39 +63,68 @@ private static final Logger logger = LoggingUtils.getLogger(ProfileVmRequestReceiver.class); - private ConcurrentHashMap<String, Integer> vmIdToPid = new ConcurrentHashMap<>(); - /** A pid that corresponds to an unknown */ private static final int UNKNOWN_VMID = -1; + private static final Response OK = new Response(ResponseType.OK); + private static final Response ERROR = new Response(ResponseType.NOK); + + static class FileTimeStampLatestFirst implements Comparator<File> { + @Override + public int compare(File o1, File o2) { + return Long.compare(o2.lastModified(), o1.lastModified()); + } + } + + static class ProfileUploaderCreator { + ProfileUploader create(ProfileDAO dao, String agentId, String vmId, int pid) { + return new ProfileUploader(dao, agentId, vmId, pid); + } + } + + private final ConcurrentHashMap<String, Integer> vmIdToPid = new ConcurrentHashMap<>(); + private final String agentId; + private final Clock clock; private final VmProfiler profiler; private final ProfileDAO dao; + private ProfileUploaderCreator uploaderCreator; + + private List<Integer> currentlyProfiledVms = new ArrayList<>(); public ProfileVmRequestReceiver(String agentId, VmProfiler profiler, ProfileDAO dao) { + this(agentId, new SystemClock(), profiler, dao, new ProfileUploaderCreator()); + } + + public ProfileVmRequestReceiver(String agentId, Clock clock, VmProfiler profiler, ProfileDAO dao, ProfileUploaderCreator uploaderCreator) { + this.clock = clock; this.profiler = profiler; this.dao = dao; + this.uploaderCreator = uploaderCreator; this.agentId = agentId; } @Override - public void vmStatusChanged(Status newStatus, String vmId, int pid) { + public synchronized void vmStatusChanged(Status newStatus, String vmId, int pid) { if (newStatus == Status.VM_ACTIVE || newStatus == Status.VM_STARTED) { - // assert not already being profiled + // TODO assert not already being profiled vmIdToPid.putIfAbsent(vmId, pid); } else { - // FIXME disable profiler if active? + disableProfilerIfActive(vmId, pid); vmIdToPid.remove(vmId, pid); } } + private void disableProfilerIfActive(String vmId, int pid) { + if (currentlyProfiledVms.contains(pid)) { + stopProfiling(vmId, pid, false); + } + } + @Override - public Response receive(Request request) { - final Response OK = new Response(ResponseType.OK); - final Response ERROR = new Response(ResponseType.NOK); - + public synchronized Response receive(Request request) { String value = request.getParameter(ProfileRequest.PROFILE_ACTION); String vmId = request.getParameter(ProfileRequest.VM_ID); @@ -97,26 +136,9 @@ switch (value) { case ProfileRequest.START_PROFILING: - logger.info("Starting profiling " + pid); - try { - profiler.startProfiling(pid); - return OK; - } catch (Exception e) { - logger.log(Level.INFO, "start profiling failed", e); - return ERROR; - } - /* should not reach here */ + return startProfiling(pid); case ProfileRequest.STOP_PROFILING: - logger.info("Stopping profiling " + pid); - try { - ProfileUploader uploader = new ProfileUploader(dao, agentId, vmId, pid); - profiler.stopProfiling(pid, uploader); - return OK; - } catch (Exception e) { - logger.log(Level.INFO, "stop profiling failed", e); - return ERROR; - } - /* should not reach here */ + return stopProfiling(vmId, pid, true); default: logger.warning("Unknown command: '" + value + "'"); return ERROR; @@ -133,4 +155,57 @@ } } + private Response startProfiling(int pid) { + logger.info("Starting profiling " + pid); + try { + profiler.startProfiling(pid); + currentlyProfiledVms.add(pid); + return OK; + } catch (Exception e) { + logger.log(Level.INFO, "start profiling failed", e); + return ERROR; + } + } + + private Response stopProfiling(String vmId, int pid, boolean alive) { + logger.info("Stopping profiling " + pid); + try { + ProfileUploader uploader = uploaderCreator.create(dao, agentId, vmId, pid); + if (alive) { + // if the VM is alive, communicate with it directly + profiler.stopProfiling(pid, uploader); + } else { + findAndUploadProfilingResultsStoredOnDisk(pid, uploader); + } + currentlyProfiledVms.remove((Integer) pid); + return OK; + } catch (Exception e) { + logger.log(Level.INFO, "stop profiling failed", e); + return ERROR; + } + } + + private void findAndUploadProfilingResultsStoredOnDisk(final int pid, ProfileUploader uploader) throws IOException { + long timeStamp = clock.getRealTimeMillis(); + // look for latest profiling data that it might have emitted on shutdown + File file = findProfilingResultFile(pid); + uploader.upload(timeStamp, file); + } + + private File findProfilingResultFile(final int pid) { + // from InstrumentationControl: + // return Files.createTempFile("thermostat-" + getProcessId(), ".perfdata", attributes); + String tmpDir = System.getProperty("java.io.tmpdir"); + File[] files = new File(tmpDir).listFiles(new FilenameFilter() { + @Override + public boolean accept(File dir, String name) { + return name.startsWith("thermostat-" + pid + "-") && name.endsWith(".perfdata"); + } + }); + + List<File> filesSortedByTimeStamp = Arrays.asList(files); + Collections.sort(filesSortedByTimeStamp, new FileTimeStampLatestFirst()); + return filesSortedByTimeStamp.get(0); + } + }
--- a/vm-profiler/agent/src/test/java/com/redhat/thermostat/vm/profiler/agent/internal/ProfileVmRequestReceiverTest.java Fri Nov 28 15:47:39 2014 -0500 +++ b/vm-profiler/agent/src/test/java/com/redhat/thermostat/vm/profiler/agent/internal/ProfileVmRequestReceiverTest.java Fri Nov 28 16:36:17 2014 -0500 @@ -37,19 +37,30 @@ package com.redhat.thermostat.vm.profiler.agent.internal; import static org.junit.Assert.assertEquals; +import static org.mockito.Matchers.anyInt; import static org.mockito.Matchers.eq; import static org.mockito.Matchers.isA; import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.never; import static org.mockito.Mockito.verify; +import static org.mockito.Mockito.when; + +import java.io.BufferedWriter; +import java.io.File; +import java.nio.charset.StandardCharsets; +import java.nio.file.Files; import org.junit.Before; import org.junit.Test; import com.redhat.thermostat.agent.VmStatusListener.Status; +import com.redhat.thermostat.common.Clock; import com.redhat.thermostat.common.command.Request; import com.redhat.thermostat.common.command.Response; import com.redhat.thermostat.common.command.Response.ResponseType; +import com.redhat.thermostat.vm.profiler.agent.internal.ProfileVmRequestReceiver.ProfileUploaderCreator; import com.redhat.thermostat.vm.profiler.common.ProfileDAO; +import com.redhat.thermostat.vm.profiler.common.ProfileInfo; import com.redhat.thermostat.vm.profiler.common.ProfileRequest; public class ProfileVmRequestReceiverTest { @@ -58,19 +69,27 @@ private static final String VM_ID = "foo"; private static final int VM_PID = 1; + private static final long TIMESTAMP = 99; private ProfileVmRequestReceiver requestReceiver; + private Clock clock; private VmProfiler profiler; private ProfileDAO dao; private ProfileUploader uploader; @Before public void setUp() { + clock = mock(Clock.class); + when(clock.getRealTimeMillis()).thenReturn(TIMESTAMP); + profiler = mock(VmProfiler.class); dao = mock(ProfileDAO.class); + uploader = mock(ProfileUploader.class); + ProfileUploaderCreator uploaderCreator = mock(ProfileUploaderCreator.class); + when(uploaderCreator.create(dao, AGENT_ID, VM_ID, VM_PID)).thenReturn(uploader); - requestReceiver = new ProfileVmRequestReceiver(AGENT_ID, profiler, dao); + requestReceiver = new ProfileVmRequestReceiver(AGENT_ID, clock, profiler, dao, uploaderCreator); } @Test @@ -94,9 +113,9 @@ @Test public void startAndStopProfiling() throws ProfilerException { Request request; - request = ProfileRequest.create(null, VM_ID, ProfileRequest.START_PROFILING); requestReceiver.vmStatusChanged(Status.VM_STARTED, VM_ID, VM_PID); + request = ProfileRequest.create(null, VM_ID, ProfileRequest.START_PROFILING); Response result = requestReceiver.receive(request); assertEquals(ResponseType.OK, result.getType()); @@ -118,4 +137,26 @@ Response result = requestReceiver.receive(request); assertEquals(ResponseType.NOK, result.getType()); } + + @Test + public void readsProfilingResultsOnVmExit() throws Exception { + Request request; + + requestReceiver.vmStatusChanged(Status.VM_STARTED, VM_ID, VM_PID); + request = ProfileRequest.create(null, VM_ID, ProfileRequest.START_PROFILING); + requestReceiver.receive(request); + + // simulate target vm exiting + File profilingResults = new File(System.getProperty("java.io.tmpdir"), "thermostat-" + VM_PID + "-foobar.perfdata"); + try (BufferedWriter writer = Files.newBufferedWriter(profilingResults.toPath(), StandardCharsets.UTF_8)) { + writer.append("test file, please ignore"); + } + + requestReceiver.vmStatusChanged(Status.VM_STOPPED, VM_ID, VM_PID); + + verify(profiler, never()).stopProfiling(anyInt(), isA(ProfileUploader.class)); + verify(uploader).upload(TIMESTAMP, profilingResults); + + profilingResults.delete(); + } }
--- a/vm-profiler/jvm-agent/src/main/java/com/redhat/thermostat/vm/profiler/agent/jvm/InstrumentationControl.java Fri Nov 28 15:47:39 2014 -0500 +++ b/vm-profiler/jvm-agent/src/main/java/com/redhat/thermostat/vm/profiler/agent/jvm/InstrumentationControl.java Fri Nov 28 16:36:17 2014 -0500 @@ -40,6 +40,7 @@ import java.io.IOException; import java.lang.instrument.Instrumentation; import java.lang.instrument.UnmodifiableClassException; +import java.lang.management.ManagementFactory; import java.nio.charset.StandardCharsets; import java.nio.file.Files; import java.nio.file.OpenOption; @@ -58,23 +59,51 @@ private final Instrumentation instrumentation; private final ProfilerInstrumentor classInstrumentor; + private final ProfileRecorder recorder; + private final ResultsFileCreator resultsFileCreator; private boolean profiling = false; + private boolean resultsWrittenToDisk = true; private String lastResults = null; public InstrumentationControl(Instrumentation instrumentation) { + this(instrumentation, new AsmBasedInstrumentor(), ProfileRecorder.getInstance(), new ResultsFileCreator()); + } + + public InstrumentationControl(Instrumentation instrumentation, + ProfilerInstrumentor instrumentor, + ProfileRecorder recorder, + ResultsFileCreator resultsFileCreator) { this.instrumentation = instrumentation; - this.classInstrumentor = new AsmBasedInstrumentor(); + this.classInstrumentor = instrumentor; + this.recorder = recorder; + this.resultsFileCreator = resultsFileCreator; + + addShutdownHookToSaveData(); + } + + private void addShutdownHookToSaveData() { + Runtime.getRuntime().addShutdownHook(new Thread() { + @Override + public void run() { + onVmShutdown(); + } + }); + } + + /** package private for testing */ + void onVmShutdown() { + writeResultsToDiskIfNotWritten(); } @Override public void startProfiling() { - System.out.println("AGENT: startProfiling()"); if (profiling) { throw new IllegalStateException("Already started"); } profiling = true; + resultsWrittenToDisk = false; instrumentation.addTransformer(classInstrumentor, true); retransformAlreadyLoadedClasses(instrumentation, classInstrumentor); @@ -82,7 +111,6 @@ @Override public void stopProfiling() { - System.out.println("AGENT: stopProfiling() called"); if (!profiling) { throw new IllegalStateException("Not profiling"); } @@ -91,8 +119,9 @@ instrumentation.removeTransformer(classInstrumentor); retransformAlreadyLoadedClasses(instrumentation, classInstrumentor); - lastResults = writeProfilingResultsToDisk(); + writeProfilingResultsToDisk(); } + private void retransformAlreadyLoadedClasses(Instrumentation instrumentation, ProfilerInstrumentor profiler) { long start = System.nanoTime(); @@ -129,33 +158,30 @@ System.out.println("AGENT: Retansforming took: " + (end - start) + "ns"); } - private String writeProfilingResultsToDisk() { - System.out.println("AGENT: Writing results to disk"); + private void writeResultsToDiskIfNotWritten() { + if (!resultsWrittenToDisk) { + writeProfilingResultsToDisk(); + } + } + + private void writeProfilingResultsToDisk() { try { - Path output = createOutput(); - OpenOption[] options = - new OpenOption[] { StandardOpenOption.WRITE, StandardOpenOption.TRUNCATE_EXISTING }; - - try (BufferedWriter out = Files.newBufferedWriter(output, StandardCharsets.UTF_8, options)) { - Map<String, AtomicLong> data = ProfileRecorder.getInstance().getData(); + ResultsFile resultsFile = resultsFileCreator.get(); + String path = resultsFile.getPath(); + try (BufferedWriter out = resultsFile.getWriter()) { + Map<String, AtomicLong> data = recorder.getData(); for (Map.Entry<String, AtomicLong> entry : data.entrySet()) { out.write(entry.getValue().get() + "\t" + entry.getKey() + "\n"); } - System.out.println("AGENT: profiling data written to " + output.toString()); - return output.toString(); + System.out.println("AGENT: profiling data written to " + path); + resultsWrittenToDisk = true; + lastResults = path; } } catch (IOException e) { e.printStackTrace(); - return null; } } - private Path createOutput() throws IOException { - Set<PosixFilePermission> perm = PosixFilePermissions.fromString("rw-------"); - FileAttribute<Set<PosixFilePermission>> attributes = PosixFilePermissions.asFileAttribute(perm); - return Files.createTempFile("thermostat", ".perfdata", attributes); - } - @Override public boolean isProfiling() { return profiling; @@ -163,8 +189,46 @@ @Override public String getProfilingDataFile() { - System.out.println("getProfilingDataFile() called. Returning : " + lastResults); return lastResults; } + static class ResultsFileCreator { + + ResultsFile get() throws IOException { + Path output = createOutput(); + return new ResultsFile(output); + } + + private Path createOutput() throws IOException { + Set<PosixFilePermission> perm = PosixFilePermissions.fromString("rw-------"); + FileAttribute<Set<PosixFilePermission>> attributes = PosixFilePermissions.asFileAttribute(perm); + // Include the pid so agent can find it. Surround pid with - to + // avoid false prefix-based matches. Otherwise the agent searching + // for "-12" may find "-123" as a valid match. + return Files.createTempFile("thermostat-" + getProcessId() + "-", ".perfdata", attributes); + } + + private String getProcessId() { + return ManagementFactory.getRuntimeMXBean().getName().split("@")[0]; + } + } + + static class ResultsFile { + + private final Path path; + + ResultsFile(Path path) { this.path = path; } + + String getPath() { return path.toString(); } + + /** Caller must close the writer when done */ + BufferedWriter getWriter() throws IOException { + OpenOption[] options = new OpenOption[] { + StandardOpenOption.WRITE, + StandardOpenOption.TRUNCATE_EXISTING + }; + + return Files.newBufferedWriter(path, StandardCharsets.UTF_8, options); + } + } }
--- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/vm-profiler/jvm-agent/src/test/java/com/redhat/thermostat/vm/profiler/agent/jvm/InstrumentationControlTest.java Fri Nov 28 16:36:17 2014 -0500 @@ -0,0 +1,169 @@ +/* + * Copyright 2012-2014 Red Hat, Inc. + * + * This file is part of Thermostat. + * + * Thermostat is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published + * by the Free Software Foundation; either version 2, or (at your + * option) any later version. + * + * Thermostat is distributed in the hope that it will be useful, but + * WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with Thermostat; see the file COPYING. If not see + * <http://www.gnu.org/licenses/>. + * + * Linking this code with other modules is making a combined work + * based on this code. Thus, the terms and conditions of the GNU + * General Public License cover the whole combination. + * + * As a special exception, the copyright holders of this code give + * you permission to link this code with independent modules to + * produce an executable, regardless of the license terms of these + * independent modules, and to copy and distribute the resulting + * executable under terms of your choice, provided that you also + * meet, for each linked independent module, the terms and conditions + * of the license of that module. An independent module is a module + * which is not derived from or based on this code. If you modify + * this code, you may extend this exception to your version of the + * library, but you are not obligated to do so. If you do not wish + * to do so, delete this exception statement from your version. + */ + +package com.redhat.thermostat.vm.profiler.agent.jvm; + +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertTrue; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.times; +import static org.mockito.Mockito.verify; +import static org.mockito.Mockito.when; + +import java.io.BufferedWriter; +import java.io.StringWriter; +import java.lang.instrument.Instrumentation; +import java.util.HashMap; +import java.util.Map; +import java.util.concurrent.atomic.AtomicLong; + +import org.junit.Before; +import org.junit.Test; + +import com.redhat.thermostat.vm.profiler.agent.jvm.InstrumentationControl.ResultsFile; +import com.redhat.thermostat.vm.profiler.agent.jvm.InstrumentationControl.ResultsFileCreator; + +public class InstrumentationControlTest { + + private Instrumentation instrumentation; + private ProfilerInstrumentor instrumentor; + private ProfileRecorder recorder; + private ResultsFileCreator resultsFileCreator; + private ResultsFile resultsFile; + + private InstrumentationControl control; + private StringWriter dataWriter; + + @Before + public void setUp() throws Exception { + instrumentation = mock(Instrumentation.class); + when(instrumentation.isModifiableClass(Object.class)).thenReturn(true); + when(instrumentation.getAllLoadedClasses()).thenReturn(new Class[] { Object.class }); + + instrumentor = mock(ProfilerInstrumentor.class); + when(instrumentor.shouldInstrument(Object.class)).thenReturn(true); + + recorder = mock(ProfileRecorder.class); + + dataWriter = new StringWriter(); + resultsFile = mock(ResultsFile.class); + when(resultsFile.getWriter()).thenReturn(new BufferedWriter(dataWriter)); + + resultsFileCreator = mock(ResultsFileCreator.class); + when(resultsFileCreator.get()).thenReturn(resultsFile); + + control = new InstrumentationControl(instrumentation, instrumentor, recorder, resultsFileCreator); + } + + @Test + public void isProfilingRepresentsCurrentProfilingState() throws Exception { + control.startProfiling(); + + assertTrue(control.isProfiling()); + + control.stopProfiling(); + + assertFalse(control.isProfiling()); + } + + @Test (expected=IllegalStateException.class) + public void startingProfilingTwiceThrowsException() throws Exception { + control.startProfiling(); + control.startProfiling(); + } + + @Test (expected=IllegalStateException.class) + public void stoppingProfilingWhenNotRunningThrowException() throws Exception { + control.stopProfiling(); + } + + @Test + public void startProfilingInstrumentAllCode() throws Exception { + control.startProfiling(); + + verify(instrumentation).addTransformer(instrumentor, true); + verify(instrumentation).retransformClasses(new Class[] { Object.class }); + } + + @Test + public void stopProfilingInstrumentsAllCode() throws Exception { + control.startProfiling(); + + control.stopProfiling(); + + verify(instrumentation).removeTransformer(instrumentor); + verify(instrumentation, times(2)).retransformClasses(new Class[] { Object.class }); + } + + @Test + public void stopProfilingSavesProfilingResultsToDisk() throws Exception { + final String DATA_LOCATION = "foobar"; + + Map<String, AtomicLong> profileData = new HashMap<>(); + profileData.put("foo", new AtomicLong(1)); + when(recorder.getData()).thenReturn(profileData); + + when(resultsFile.getPath()).thenReturn(DATA_LOCATION); + control.startProfiling(); + + control.stopProfiling(); + + verify(resultsFile).getWriter(); + assertEquals("1\tfoo\n", dataWriter.toString()); + assertEquals(DATA_LOCATION, control.getProfilingDataFile()); + } + + @Test + public void vmShutdownSaveDataToDisk() throws Exception { + final String DATA_LOCATION = "foobar"; + + Map<String, AtomicLong> profileData = new HashMap<>(); + profileData.put("foo", new AtomicLong(1)); + when(recorder.getData()).thenReturn(profileData); + + when(resultsFile.getPath()).thenReturn(DATA_LOCATION); + + control.startProfiling(); + + // simulate vm shutdown: + control.onVmShutdown(); + + verify(resultsFile).getWriter(); + assertEquals("1\tfoo\n", dataWriter.toString()); + assertEquals(DATA_LOCATION, control.getProfilingDataFile()); + } +}