1 /*
   2  * Copyright (c) 2018, Oracle and/or its affiliates. All rights reserved.
   3  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
   4  *
   5  * This code is free software; you can redistribute it and/or modify it
   6  * under the terms of the GNU General Public License version 2 only, as
   7  * published by the Free Software Foundation.  Oracle designates this
   8  * particular file as subject to the "Classpath" exception as provided
   9  * by Oracle in the LICENSE file that accompanied this code.
  10  *
  11  * This code is distributed in the hope that it will be useful, but WITHOUT
  12  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  13  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
  14  * version 2 for more details (a copy is included in the LICENSE file that
  15  * accompanied this code).
  16  *
  17  * You should have received a copy of the GNU General Public License version
  18  * 2 along with this work; if not, write to the Free Software Foundation,
  19  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
  20  *
  21  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
  22  * or visit www.oracle.com if you need additional information or have any
  23  * questions.
  24  */
  25 
  26 package jdk.jfr.event.io;
  27 
  28 import java.io.File;
  29 import java.io.IOException;
  30 import java.io.RandomAccessFile;
  31 import java.time.Duration;
  32 import java.time.Instant;
  33 import java.util.ArrayList;
  34 import java.util.Comparator;
  35 import java.util.List;
  36 
  37 import jdk.jfr.Recording;
  38 import jdk.jfr.consumer.RecordedEvent;
  39 import jdk.test.lib.Asserts;
  40 import jdk.test.lib.jfr.Events;
  41 import jdk.test.lib.thread.TestThread;
  42 import jdk.test.lib.thread.XRun;
  43 
  44 
  45 /**
  46  * @test
  47  * @summary Verify the event time stamp and thread name
  48  * @key jfr
  49  * @requires vm.hasJFR
  50  * @library /test/lib /test/jdk
  51  * @run main/othervm -XX:+UnlockExperimentalVMOptions -XX:-UseFastUnorderedTimeStamps jdk.jfr.event.io.TestRandomAccessFileThread
  52  */
  53 
  54 // TODO: This test should work without -XX:-UseFastUnorderedTimeStamps
  55 
  56 // The test uses 2 threads to read and write to a file.
  57 // The number of bytes in each read/write operation is increased by 1.
  58 // By looking at the number of bytes in each event, we know in what order
  59 // the events should arrive. This is used to verify the event time stamps.
  60 public class TestRandomAccessFileThread {
  61     private static final int OP_COUNT = 100;    // Total number of read/write operations.
  62     private static volatile int writeCount = 0; // Number of writes executed.
  63 
  64     public static void main(String[] args) throws Throwable {
  65         File tmp = File.createTempFile("TestRandomAccessFileThread", ".tmp", new File("."));
  66         tmp.deleteOnExit();
  67 
  68         Recording recording = new Recording();
  69         recording.enable(IOEvent.EVENT_FILE_READ).withThreshold(Duration.ofMillis(0));
  70         recording.enable(IOEvent.EVENT_FILE_WRITE).withThreshold(Duration.ofMillis(0));
  71         recording.start();
  72 
  73         TestThread writerThread = new TestThread(new XRun() {
  74             @Override
  75             public void xrun() throws IOException {
  76                 final byte[] buf = new byte[OP_COUNT];
  77                 for (int i = 0; i < buf.length; ++i) {
  78                     buf[i] = (byte)((i + 'a') % 255);
  79                 }
  80                 try (RandomAccessFile raf = new RandomAccessFile(tmp, "rwd")) {
  81                     for(int i = 0; i < OP_COUNT; ++i) {
  82                         raf.write(buf, 0, i + 1);
  83                         writeCount++;
  84                     }
  85                 }
  86             }}, "TestWriterThread");
  87 
  88             TestThread readerThread = new TestThread(new XRun() {
  89             @Override
  90             public void xrun() throws IOException {
  91                 try (RandomAccessFile raf = new RandomAccessFile(tmp, "r")) {
  92                     byte[] buf = new byte[OP_COUNT];
  93                     for(int i = 0; i < OP_COUNT; ++i) {
  94                         while (writeCount <= i) {
  95                             // No more data to read. Wait for writer thread.
  96                             Thread.yield();
  97                         }
  98                         int expectedSize = i + 1;
  99                         int actualSize = raf.read(buf, 0, expectedSize);
 100                         Asserts.assertEquals(actualSize, expectedSize, "Wrong read size. Probably test error.");
 101                     }
 102                 }
 103             }}, "TestReaderThread");
 104 
 105             readerThread.start();
 106             writerThread.start();
 107             writerThread.joinAndThrow();
 108             readerThread.joinAndThrow();
 109             recording.stop();
 110 
 111             List<RecordedEvent> events = Events.fromRecording(recording);
 112             events.sort(new EventComparator());
 113 
 114             List<RecordedEvent> readEvents = new ArrayList<>();
 115             List<RecordedEvent> writeEvents = new ArrayList<>();
 116             for (RecordedEvent event : events) {
 117                 if (!isOurEvent(event, tmp)) {
 118                     continue;
 119                 }
 120                 logEventSummary(event);
 121                 if (Events.isEventType(event,IOEvent.EVENT_FILE_READ)) {
 122                     readEvents.add(event);
 123                 } else {
 124                     writeEvents.add(event);
 125                 }
 126             }
 127 
 128             verifyThread(readEvents, readerThread);
 129             verifyThread(writeEvents, writerThread);
 130             verifyBytes(readEvents, "bytesRead");
 131             verifyBytes(writeEvents, "bytesWritten");
 132             verifyTimes(readEvents);
 133             verifyTimes(writeEvents);
 134             verifyReadWriteTimes(readEvents, writeEvents);
 135 
 136             Asserts.assertEquals(readEvents.size(), OP_COUNT, "Wrong number of read events");
 137             Asserts.assertEquals(writeEvents.size(), OP_COUNT, "Wrong number of write events");
 138         }
 139 
 140         private static void logEventSummary(RecordedEvent event) {
 141             boolean isRead = Events.isEventType(event, IOEvent.EVENT_FILE_READ);
 142             String name = isRead ? "read " : "write";
 143             String bytesField = isRead ? "bytesRead" : "bytesWritten";
 144             long bytes = Events.assertField(event, bytesField).getValue();
 145             long commit = Events.assertField(event, "startTime").getValue();
 146             Instant start = event.getStartTime();
 147             Instant end = event.getEndTime();
 148             System.out.printf("%s: bytes=%d, commit=%d, start=%s, end=%s%n", name, bytes, commit, start, end);
 149         }
 150 
 151         private static void verifyThread(List<RecordedEvent> events, Thread thread) {
 152             events.stream().forEach(e -> Events.assertEventThread(e, thread));
 153         }
 154 
 155         private static void verifyBytes(List<RecordedEvent> events, String fieldName) {
 156             long expectedBytes = 0;
 157             for (RecordedEvent event : events) {
 158                 Events.assertField(event, fieldName).equal(++expectedBytes);
 159             }
 160         }
 161 
 162         // Verify that all times are increasing
 163         private static void verifyTimes(List<RecordedEvent> events) {
 164             RecordedEvent prev = null;
 165             for (RecordedEvent curr : events) {
 166                 if (prev != null) {
 167                     try {
 168                         Asserts.assertGreaterThanOrEqual(curr.getStartTime(), prev.getStartTime(), "Wrong startTime");
 169                         Asserts.assertGreaterThanOrEqual(curr.getEndTime(), prev.getEndTime(), "Wrong endTime");
 170                         long commitPrev = Events.assertField(prev, "startTime").getValue();
 171                         long commitCurr = Events.assertField(curr, "startTime").getValue();
 172                         Asserts.assertGreaterThanOrEqual(commitCurr, commitPrev, "Wrong commitTime");
 173                     } catch (Exception e) {
 174                         System.out.println("Error: " + e.getMessage());
 175                         System.out.println("Prev Event: " + prev);
 176                         System.out.println("Curr Event: " + curr);
 177                         throw e;
 178                     }
 179                 }
 180                 prev = curr;
 181             }
 182         }
 183 
 184         // Verify that all times are increasing
 185         private static void verifyReadWriteTimes(List<RecordedEvent> readEvents, List<RecordedEvent> writeEvents) {
 186             List<RecordedEvent> events = new ArrayList<>();
 187             events.addAll(readEvents);
 188             events.addAll(writeEvents);
 189             events.sort(new EventComparator());
 190 
 191             int countRead = 0;
 192             int countWrite = 0;
 193             for (RecordedEvent event : events) {
 194                 if (Events.isEventType(event, IOEvent.EVENT_FILE_READ)) {
 195                     ++countRead;
 196                 } else {
 197                     ++countWrite;
 198                 }
 199                 // We can not read from the file before it has been written.
 200                 // This check verifies that times of different threads are correct.
 201                 // Since the read and write are from different threads, it is possible that the read
 202                 // is committed before the same write.
 203                 // But read operation may only be 1 step ahead of the write operation.
 204                 Asserts.assertLessThanOrEqual(countRead, countWrite + 1, "read must be after write");
 205             }
 206         }
 207 
 208         private static boolean isOurEvent(RecordedEvent event, File file) {
 209             if (!Events.isEventType(event, IOEvent.EVENT_FILE_READ) &&
 210                 !Events.isEventType(event, IOEvent.EVENT_FILE_WRITE)) {
 211                 return false;
 212             }
 213             String path = Events.assertField(event, "path").getValue();
 214             return file.getPath().equals(path);
 215         }
 216 
 217         private static class EventComparator implements Comparator<RecordedEvent> {
 218             @Override
 219             public int compare(RecordedEvent a, RecordedEvent b) {
 220                 long commitA = Events.assertField(a, "startTime").getValue();
 221                 long commitB = Events.assertField(b, "startTime").getValue();
 222                 return Long.compare(commitA, commitB);
 223             }
 224         }
 225 
 226 }