Mercurial > hg > release > thermostat-1.6
changeset 2003:7e6a52dfd303
Add start and stop times to profiler
Reviewed by: jkang
Review Thread: http://icedtea.classpath.org/pipermail/thermostat/2016-June/020122.html
PR3048
line wrap: on
line diff
--- a/vm-profiler/agent/src/main/java/com/redhat/thermostat/vm/profiler/agent/internal/ProfileUploader.java Thu Jun 30 15:48:32 2016 -0400 +++ b/vm-profiler/agent/src/main/java/com/redhat/thermostat/vm/profiler/agent/internal/ProfileUploader.java Thu Jun 30 16:28:18 2016 -0400 @@ -57,14 +57,15 @@ this.vmId = vmId; } - public void upload(long timeStamp, File data) throws IOException { + public void upload(long startTimeStamp, long stopTimeStamp, final File data) throws IOException { // FIXME resource leak: file is never closed - upload(timeStamp, new FileInputStream(data)); + InputStream stream = new FileInputStream(data); + upload(startTimeStamp, stopTimeStamp, stream); } - public void upload(long timeStamp, InputStream data) throws IOException { + public void upload(final long startTimeStamp, final long stopTimeStamp, final InputStream data) throws IOException { String id = UUID.randomUUID().toString(); - ProfileInfo info = new ProfileInfo(agentId, vmId, timeStamp, id); + ProfileInfo info = new ProfileInfo(agentId, vmId, startTimeStamp, stopTimeStamp, id); dao.saveProfileData(info, data); } }
--- a/vm-profiler/agent/src/main/java/com/redhat/thermostat/vm/profiler/agent/internal/VmProfiler.java Thu Jun 30 15:48:32 2016 -0400 +++ b/vm-profiler/agent/src/main/java/com/redhat/thermostat/vm/profiler/agent/internal/VmProfiler.java Thu Jun 30 16:28:18 2016 -0400 @@ -43,7 +43,9 @@ import java.util.Arrays; import java.util.Collections; import java.util.Comparator; +import java.util.HashMap; import java.util.List; +import java.util.Map; import java.util.Objects; import java.util.Properties; import java.util.logging.Logger; @@ -74,6 +76,7 @@ private final List<Integer> vmsWithAgentLoaded = new ArrayList<>(); private final List<Integer> currentlyProfiledVmPids = new ArrayList<>(); + private final Map<Integer, Long> vmStartTimeStamps = new HashMap<>(); private final VmIdToPidMapper vmIdToPid = new VmIdToPidMapper(); @@ -150,8 +153,10 @@ remote.startProfiling(pid); + long startTime = clock.getRealTimeMillis(); currentlyProfiledVmPids.add(pid); - dao.addStatus(new ProfileStatusChange(agentId, vmId, clock.getRealTimeMillis(), true)); + vmStartTimeStamps.put(pid, startTime); + dao.addStatus(new ProfileStatusChange(agentId, vmId, startTime, true)); } public synchronized void stopProfiling(String vmId) throws ProfilerException { @@ -175,21 +180,27 @@ findAndUploadProfilingResultsStoredOnDisk(pid, uploader); } dao.addStatus(new ProfileStatusChange(agentId, vmId, clock.getRealTimeMillis(), false)); + vmStartTimeStamps.remove(pid); currentlyProfiledVmPids.remove((Integer) pid); } private void stopRemoteProfilerAndUploadResults(int pid, ProfileUploader uploader) throws ProfilerException { remote.stopProfiling(pid); + long startTimeStamp = vmStartTimeStamps.get(pid); + long stopTimeStamp = clock.getRealTimeMillis(); String profilingDataFile = remote.getProfilingDataFile(pid); - upload(uploader, clock.getRealTimeMillis(), new File(profilingDataFile)); + + uploadAndDelete(uploader, startTimeStamp, stopTimeStamp, new File(profilingDataFile)); } private void findAndUploadProfilingResultsStoredOnDisk(final int pid, ProfileUploader uploader) throws ProfilerException { - long timeStamp = clock.getRealTimeMillis(); + long startTimeStamp = vmStartTimeStamps.get(pid); + long stopTimeStamp = clock.getRealTimeMillis(); // look for latest profiling data that it might have emitted on shutdown File file = findProfilingResultFile(pid); - upload(uploader, timeStamp, file); + + uploadAndDelete(uploader, startTimeStamp, stopTimeStamp, file); } private File findProfilingResultFile(final int pid) { @@ -207,10 +218,9 @@ Collections.sort(filesSortedByTimeStamp, new MostRecentFileFirst()); return filesSortedByTimeStamp.get(0); } - - private void upload(ProfileUploader uploader, long timeStamp, File file) throws ProfilerException { + private void uploadAndDelete(ProfileUploader uploader, final long startTimeStamp, final long stopTimeStamp, final File file) throws ProfilerException { try { - uploader.upload(clock.getRealTimeMillis(), file); + uploader.upload(startTimeStamp, stopTimeStamp, file); } catch (IOException e) { throw new ProfilerException("Unable to save profiling data into storage", e); }
--- a/vm-profiler/agent/src/test/java/com/redhat/thermostat/vm/profiler/agent/internal/ProfileUploaderTest.java Thu Jun 30 15:48:32 2016 -0400 +++ b/vm-profiler/agent/src/test/java/com/redhat/thermostat/vm/profiler/agent/internal/ProfileUploaderTest.java Thu Jun 30 16:28:18 2016 -0400 @@ -77,13 +77,14 @@ ArgumentCaptor<ProfileInfo> profileInfoCaptor = ArgumentCaptor.forClass(ProfileInfo.class); - uploader.upload(TIME, input); + uploader.upload(TIME, TIME, input); verify(dao).saveProfileData(profileInfoCaptor.capture(), eq(input)); ProfileInfo profileInfo = profileInfoCaptor.getValue(); assertEquals(AGENT_ID, profileInfo.getAgentId()); assertEquals(VM_ID, profileInfo.getVmId()); - assertEquals(TIME, profileInfo.getTimeStamp()); + assertEquals(TIME, profileInfo.getStartTimeStamp()); + assertEquals(TIME, profileInfo.getStopTimeStamp()); assertNotNull(profileInfo.getProfileId()); } }
--- a/vm-profiler/agent/src/test/java/com/redhat/thermostat/vm/profiler/agent/internal/VmProfilerTest.java Thu Jun 30 15:48:32 2016 -0400 +++ b/vm-profiler/agent/src/test/java/com/redhat/thermostat/vm/profiler/agent/internal/VmProfilerTest.java Thu Jun 30 16:28:18 2016 -0400 @@ -36,6 +36,7 @@ package com.redhat.thermostat.vm.profiler.agent.internal; +import static org.mockito.Matchers.eq; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.never; import static org.mockito.Mockito.times; @@ -191,7 +192,7 @@ verify(dao).addStatus(new ProfileStatusChange(AGENT_ID, VM_ID, TIMESTAMP, false)); verify(remote).stopProfiling(PID); - verify(uploader).upload(TIMESTAMP, new File(FILE)); + verify(uploader).upload(eq(TIMESTAMP), eq(TIMESTAMP), eq(new File(FILE))); verifyNoMoreInteractions(uploader); } @@ -208,7 +209,7 @@ profiler.vmStopped(VM_ID, PID); verify(remote, never()).stopProfiling(PID); - verify(uploader).upload(TIMESTAMP, profilingResults); + verify(uploader).upload(eq(TIMESTAMP), eq(TIMESTAMP), eq(profilingResults)); verify(dao).addStatus(new ProfileStatusChange(AGENT_ID, VM_ID, TIMESTAMP, false)); profilingResults.delete();
--- a/vm-profiler/client-swing/src/main/java/com/redhat/thermostat/vm/profiler/client/swing/internal/SwingVmProfileView.java Thu Jun 30 15:48:32 2016 -0400 +++ b/vm-profiler/client-swing/src/main/java/com/redhat/thermostat/vm/profiler/client/swing/internal/SwingVmProfileView.java Thu Jun 30 16:28:18 2016 -0400 @@ -141,7 +141,7 @@ if (value instanceof Profile) { Profile profile = (Profile) value; value = translator.localize(LocaleResources.PROFILER_LIST_ITEM, - profile.name, new Date(profile.timeStamp).toString()).getContents(); + profile.name, new Date(profile.startTimeStamp).toString(), new Date(profile.stopTimeStamp).toString()).getContents(); } return super.getListCellRendererComponent(list, value, index, isSelected, cellHasFocus); }
--- a/vm-profiler/client-swing/src/main/java/com/redhat/thermostat/vm/profiler/client/swing/internal/VmProfileController.java Thu Jun 30 15:48:32 2016 -0400 +++ b/vm-profiler/client-swing/src/main/java/com/redhat/thermostat/vm/profiler/client/swing/internal/VmProfileController.java Thu Jun 30 16:28:18 2016 -0400 @@ -359,7 +359,8 @@ List<ProfileInfo> profileInfos = profileDao.getAllProfileInfo(vm, new Range<>(start, end)); List<Profile> profiles = new ArrayList<>(); for (ProfileInfo profileInfo : profileInfos) { - Profile profile = new Profile(profileInfo.getProfileId(), profileInfo.getTimeStamp()); + Profile profile = new Profile(profileInfo.getProfileId(), + profileInfo.getStartTimeStamp(), profileInfo.getStopTimeStamp()); profiles.add(profile); } @@ -400,7 +401,7 @@ static class ByTimeStamp implements Comparator<Profile> { @Override public int compare(Profile o1, Profile o2) { - return Long.compare(o1.timeStamp, o2.timeStamp); + return Long.compare(o1.startTimeStamp, o2.startTimeStamp); } }
--- a/vm-profiler/client-swing/src/main/java/com/redhat/thermostat/vm/profiler/client/swing/internal/VmProfileView.java Thu Jun 30 15:48:32 2016 -0400 +++ b/vm-profiler/client-swing/src/main/java/com/redhat/thermostat/vm/profiler/client/swing/internal/VmProfileView.java Thu Jun 30 16:28:18 2016 -0400 @@ -51,10 +51,12 @@ static class Profile { public final String name; - public final long timeStamp; - public Profile(String name, long timeStamp) { + public final long startTimeStamp; + public final long stopTimeStamp; + public Profile(String name, long startTimeStamp, long stopTimeStamp) { this.name = name; - this.timeStamp = timeStamp; + this.startTimeStamp = startTimeStamp; + this.stopTimeStamp = stopTimeStamp; } @Override @@ -67,12 +69,13 @@ } Profile other = (Profile) obj; return Objects.equals(this.name, other.name) - && Objects.equals(this.timeStamp, other.timeStamp); + && Objects.equals(this.startTimeStamp, other.startTimeStamp) + && Objects.equals(this.stopTimeStamp, other.stopTimeStamp); } @Override public String toString() { - return "Profile (" + this.name + ", " + this.timeStamp + ")"; + return "Profile (" + this.name + ", [" + this.startTimeStamp + "," + this.stopTimeStamp + "] )"; } }
--- a/vm-profiler/client-swing/src/main/resources/com/redhat/thermostat/vm/profiler/client/swing/internal/strings.properties Thu Jun 30 15:48:32 2016 -0400 +++ b/vm-profiler/client-swing/src/main/resources/com/redhat/thermostat/vm/profiler/client/swing/internal/strings.properties Thu Jun 30 16:28:18 2016 -0400 @@ -13,7 +13,7 @@ STOP_PROFILING = Stop Profiling STOPPING_PROFILING = Stopping profiling\u2026 -PROFILER_LIST_ITEM = Session @ {1} ({0}) +PROFILER_LIST_ITEM = Session {1} to {2} ({0}) PROFILER_RESULTS_TABLE = Table PROFILER_RESULTS_TREEMAP = TreeMap PROFILER_RESULTS_METHOD = Method
--- a/vm-profiler/client-swing/src/test/java/com/redhat/thermostat/vm/profiler/client/swing/internal/SwingVmProfileViewTest.java Thu Jun 30 15:48:32 2016 -0400 +++ b/vm-profiler/client-swing/src/test/java/com/redhat/thermostat/vm/profiler/client/swing/internal/SwingVmProfileViewTest.java Thu Jun 30 16:28:18 2016 -0400 @@ -246,7 +246,7 @@ final JListFixture profileJList = frame.list("PROFILE_LIST"); final List<VmProfileView.Profile> availableRuns = new ArrayList<>(); - availableRuns.add(new VmProfileView.Profile("profile1", 1000)); + availableRuns.add(new VmProfileView.Profile("profile1", 0, 1000)); view.setAvailableProfilingRuns(availableRuns); profileJList.clickItem(0); @@ -413,7 +413,7 @@ public void testProfileItemRendererWithProfileValue() { SwingVmProfileView.ProfileItemRenderer renderer = new SwingVmProfileView.ProfileItemRenderer(); - VmProfileView.Profile value = new VmProfileView.Profile("profile", 1000); + VmProfileView.Profile value = new VmProfileView.Profile("profile", 0, 1000); Component result = renderer.getListCellRendererComponent( mock(JList.class), value, 0, true, true); @@ -421,7 +421,7 @@ (SwingVmProfileView.ProfileItemRenderer) result; String expectedValue = translator.localize(LocaleResources.PROFILER_LIST_ITEM, - value.name, new Date(value.timeStamp).toString()).getContents(); + value.name, new Date(value.startTimeStamp).toString(), new Date(value.stopTimeStamp).toString()).getContents(); assertEquals(expectedValue, resultRenderer.getText()); }
--- a/vm-profiler/client-swing/src/test/java/com/redhat/thermostat/vm/profiler/client/swing/internal/VmProfileControllerTest.java Thu Jun 30 15:48:32 2016 -0400 +++ b/vm-profiler/client-swing/src/test/java/com/redhat/thermostat/vm/profiler/client/swing/internal/VmProfileControllerTest.java Thu Jun 30 16:28:18 2016 -0400 @@ -227,7 +227,7 @@ ArgumentCaptor<Runnable> runnableCaptor = ArgumentCaptor.forClass(Runnable.class); verify(timer).setAction(runnableCaptor.capture()); - ProfileInfo profile = new ProfileInfo(AGENT_ID, VM_ID, PROFILE_TIMESTAMP, PROFILE_ID); + ProfileInfo profile = new ProfileInfo(AGENT_ID, VM_ID, PROFILE_TIMESTAMP, PROFILE_TIMESTAMP, PROFILE_ID); when(profileDao.getAllProfileInfo(vm, new Range<>(SOME_TIMESTAMP - TimeUnit.DAYS.toMillis(1), SOME_TIMESTAMP))) @@ -243,7 +243,7 @@ verify(view).setAvailableProfilingRuns(listCaptor.capture()); List<Profile> resultList = listCaptor.getValue(); assertEquals(1, resultList.size()); - assertEquals(PROFILE_TIMESTAMP, resultList.get(0).timeStamp); + assertEquals(PROFILE_TIMESTAMP, resultList.get(0).startTimeStamp); verify(view, atLeastOnce()).setViewControlsEnabled(true); } @@ -348,7 +348,7 @@ controller = createController(); final String PROFILE_DATA = "1 foo"; - Profile PROFILE = new Profile(PROFILE_ID, 10); + Profile PROFILE = new Profile(PROFILE_ID, 10, 10); when(view.getSelectedProfile()).thenReturn(PROFILE); when(profileDao.loadProfileDataById(vm, PROFILE_ID)).thenReturn(
--- a/vm-profiler/common/src/main/java/com/redhat/thermostat/vm/profiler/common/ProfileInfo.java Thu Jun 30 15:48:32 2016 -0400 +++ b/vm-profiler/common/src/main/java/com/redhat/thermostat/vm/profiler/common/ProfileInfo.java Thu Jun 30 16:28:18 2016 -0400 @@ -39,22 +39,22 @@ import com.redhat.thermostat.storage.core.Entity; import com.redhat.thermostat.storage.core.Persist; import com.redhat.thermostat.storage.model.BasePojo; -import com.redhat.thermostat.storage.model.TimeStampedPojo; @Entity -public class ProfileInfo extends BasePojo implements TimeStampedPojo { +public class ProfileInfo extends BasePojo { private String vmId; - // FIXME should be two fields for start time and stop time - private long timeStamp; + private long startTimeStamp; + private long stopTimeStamp; private String profileId; - public ProfileInfo(String agentId, String vmId, long timeStamp, String profileId) { + public ProfileInfo(String agentId, String vmId, long startTimeStamp, long stopTimeStamp, String profileId) { super(agentId); this.vmId = vmId; - this.timeStamp = timeStamp; + this.startTimeStamp = startTimeStamp; + this.stopTimeStamp = stopTimeStamp; this.profileId = profileId; } @@ -74,14 +74,23 @@ } @Persist - public void setTimeStamp(long timeStamp) { - this.timeStamp = timeStamp; + public void setStartTimeStamp(long startTimeStamp) { + this.startTimeStamp = startTimeStamp; } @Persist - @Override - public long getTimeStamp() { - return this.timeStamp; + public long getStartTimeStamp() { + return this.startTimeStamp; + } + + @Persist + public void setStopTimeStamp(long stopTimeStamp) { + this.stopTimeStamp = stopTimeStamp; + } + + @Persist + public long getStopTimeStamp() { + return this.stopTimeStamp; } @Persist
--- a/vm-profiler/common/src/main/java/com/redhat/thermostat/vm/profiler/common/internal/ProfileDAOImpl.java Thu Jun 30 15:48:32 2016 -0400 +++ b/vm-profiler/common/src/main/java/com/redhat/thermostat/vm/profiler/common/internal/ProfileDAOImpl.java Thu Jun 30 16:28:18 2016 -0400 @@ -37,6 +37,7 @@ package com.redhat.thermostat.vm.profiler.common.internal; import java.io.InputStream; +import java.util.ArrayList; import java.util.List; import java.util.logging.Level; import java.util.logging.Logger; @@ -51,6 +52,7 @@ import com.redhat.thermostat.storage.core.StatementDescriptor; import com.redhat.thermostat.storage.core.StatementExecutionException; import com.redhat.thermostat.storage.core.Storage; +import com.redhat.thermostat.storage.core.StorageException; import com.redhat.thermostat.storage.core.VmRef; import com.redhat.thermostat.storage.core.VmTimeIntervalPojoListGetter; import com.redhat.thermostat.storage.model.BasePojo; @@ -62,35 +64,43 @@ private static final Logger logger = LoggingUtils.getLogger(ProfileDAOImpl.class); + private static final Key<Long> KEY_START_TIME_STAMP = new Key<>("startTimeStamp"); + private static final Key<Long> KEY_STOP_TIME_STAMP = new Key<>("stopTimeStamp"); + private static final Key<String> KEY_PROFILE_ID = new Key<>("profileId"); static final Category<ProfileInfo> PROFILE_INFO_CATEGORY = new Category<>( "profile-info", ProfileInfo.class, - Key.AGENT_ID, Key.VM_ID, Key.TIMESTAMP, KEY_PROFILE_ID); + Key.AGENT_ID, Key.VM_ID, KEY_START_TIME_STAMP, KEY_STOP_TIME_STAMP, KEY_PROFILE_ID); static final String PROFILE_INFO_DESC_ADD = "" + "ADD " + PROFILE_INFO_CATEGORY.getName() + " SET " + " '" + Key.AGENT_ID.getName() + "' = ?s ," + " '" + Key.VM_ID.getName() + "' = ?s ," - + " '" + Key.TIMESTAMP.getName() + "' = ?l ," + + " '" + KEY_START_TIME_STAMP.getName() + "' = ?l ," + + " '" + KEY_STOP_TIME_STAMP.getName() + "' = ?l ," + " '" + KEY_PROFILE_ID.getName() + "' = ?s"; static final String PROFILE_INFO_DESC_QUERY_LATEST = "QUERY " + PROFILE_INFO_CATEGORY.getName() + " WHERE '" + Key.AGENT_ID.getName() + "' = ?s AND '" + Key.VM_ID.getName() + "' = ?s SORT '" - + Key.TIMESTAMP.getName() + "' DSC LIMIT 1"; + + KEY_STOP_TIME_STAMP.getName() + "' DSC LIMIT 1"; static final String PROFILE_INFO_DESC_QUERY_BY_ID = "QUERY " + PROFILE_INFO_CATEGORY.getName() + " WHERE '" + Key.AGENT_ID.getName() + "' = ?s AND '" + Key.VM_ID.getName() + "' = ?s AND '" - + Key.TIMESTAMP.getName() + "' = ?s LIMIT 1"; + + KEY_STOP_TIME_STAMP.getName() + "' = ?s LIMIT 1"; - // internal information of VmTimeIntervalPojoListGetter being leaked :( - static final String PROFILE_INFO_DESC_INTERVAL_QUERY = String.format( - VmTimeIntervalPojoListGetter.VM_INTERVAL_QUERY_FORMAT, ProfileDAOImpl.PROFILE_INFO_CATEGORY.getName()); + static final String PROFILE_INFO_DESC_INTERVAL_QUERY = "QUERY " + + PROFILE_INFO_CATEGORY.getName() + " WHERE '" + + Key.AGENT_ID.getName() + "' = ?s AND '" + + Key.VM_ID.getName() + "' = ?s AND '" + + KEY_STOP_TIME_STAMP.getName() + "' >= ?l AND '" + + KEY_STOP_TIME_STAMP.getName() + "' < ?l SORT '" + + KEY_STOP_TIME_STAMP.getName() + "' DSC"; private static final Key<Boolean> KEY_PROFILE_STARTED = new Key<>("started"); @@ -113,14 +123,11 @@ + Key.TIMESTAMP.getName() + "' DSC LIMIT 1"; private final Storage storage; - private final VmTimeIntervalPojoListGetter<ProfileInfo> getter; public ProfileDAOImpl(Storage storage) { this.storage = storage; this.storage.registerCategory(PROFILE_INFO_CATEGORY); this.storage.registerCategory(PROFILE_STATUS_CATEGORY); - - this.getter = new VmTimeIntervalPojoListGetter<>(storage, PROFILE_INFO_CATEGORY); } @Override @@ -136,8 +143,9 @@ prepared = storage.prepareStatement(desc); prepared.setString(0, info.getAgentId()); prepared.setString(1, info.getVmId()); - prepared.setLong(2, info.getTimeStamp()); - prepared.setString(3, info.getProfileId()); + prepared.setLong(2, info.getStartTimeStamp()); + prepared.setLong(3, info.getStopTimeStamp()); + prepared.setString(4, info.getProfileId()); prepared.execute(); } catch (DescriptorParsingException e) { logger.log(Level.SEVERE, "Preparing stmt '" + desc + "' failed!", e); @@ -148,7 +156,30 @@ @Override public List<ProfileInfo> getAllProfileInfo(VmRef vm, Range<Long> timeRange) { - return getter.getLatest(vm, timeRange.getMin(), timeRange.getMax()); + StatementDescriptor<ProfileInfo> desc = new StatementDescriptor<>(PROFILE_INFO_CATEGORY, PROFILE_INFO_DESC_INTERVAL_QUERY); + PreparedStatement<ProfileInfo> prepared; + Cursor<ProfileInfo> cursor = null; + try { + prepared = storage.prepareStatement(desc); + prepared.setString(0, vm.getHostRef().getAgentId()); + prepared.setString(1, vm.getVmId()); + prepared.setLong(2, timeRange.getMin()); + prepared.setLong(3, timeRange.getMax()); + cursor = prepared.executeQuery(); + } catch (DescriptorParsingException e) { + logger.log(Level.SEVERE, "Preparing stmt '" + desc + "' failed!", e); + } catch (StatementExecutionException e) { + logger.log(Level.SEVERE, "Executing stmt '" + desc + "' failed!", e); + } + + List<ProfileInfo> list = new ArrayList<>(); + if (cursor != null) { + while (cursor.hasNext()) { + list.add(cursor.next()); + } + } + + return list; } @Override