<NME> MidiTest.java
<BEF> /*
 * Copyright (C) 2016 The Android Open Source Project
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *      http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

package org.chromium.latency.walt;

import android.annotation.TargetApi;
import android.content.Context;
import android.media.midi.MidiDevice;
import android.media.midi.MidiDeviceInfo;
import android.media.midi.MidiInputPort;
import android.media.midi.MidiManager;
import android.media.midi.MidiOutputPort;
import android.media.midi.MidiReceiver;
import android.os.Handler;

import java.io.IOException;
import java.util.ArrayList;
import java.util.Locale;

import static org.chromium.latency.walt.Utils.getIntPreference;

@TargetApi(23)
class MidiTest extends BaseTest {

    private Handler handler = new Handler();

    private static final String TEENSY_MIDI_NAME = "Teensyduino Teensy MIDI";
    private static final byte[] noteMsg = {(byte) 0x90, (byte) 99, (byte) 0};

    private MidiManager midiManager;
    private MidiDevice midiDevice;
    // Output and Input here are with respect to the MIDI device, not the Android device.
    private MidiOutputPort midiOutputPort;
    private MidiInputPort midiInputPort;
    private boolean isConnecting = false;
    private long last_tWalt = 0;
    private long last_tSys = 0;
    private long last_tJava = 0;
    private int inputSyncAfterRepetitions = 100;
    private int outputSyncAfterRepetitions = 20; // TODO: implement periodic clock sync for output
    private long last_tSys = 0;
    private long last_tJava = 0;

    private static int syncAfterRepetitions = 100;
    private int mRepetitions = 50;
    private int mRepetitionsDone;
    private ArrayList<Double> deltasToSys = new ArrayList<>();
    private ArrayList<Double> deltasTotal = new ArrayList<>();

    MidiTest(Context context) {
        super(context);
        inputRepetitions = getIntPreference(context, R.string.preference_midi_in_reps, 100);
        outputRepetitions = getIntPreference(context, R.string.preference_midi_out_reps, 10);
        midiManager = (MidiManager) context.getSystemService(Context.MIDI_SERVICE);
        findMidiDevice();
    }

    MidiTest(Context context, AutoRunFragment.ResultHandler resultHandler) {
        this(context);
        this.resultHandler = resultHandler;
    }
        this.resultHandler = resultHandler;
    }

    void setRepetitions (int repetitions) {
        mRepetitions = repetitions;
    }

    void testMidiOut() {
                logger.log("Still connecting...");
                handler.post(new Runnable() {
                    @Override
                    public void run() {
                        testMidiOut();
                    }
                });
            } else {
                logger.log("MIDI device is not open!");
                if (testStateListener != null) testStateListener.onTestStoppedWithError();
            }
            return;
        }
        try {
            setupMidiOut();
        } catch (IOException e) {
            logger.log("Error setting up test: " + e.getMessage());
            logger.log("Error setting up test: " + e.getMessage());
            return;
        }
        scheduleNote();
        handler.postDelayed(cancelMidiOutRunnable, noteDelay + timeout);
    }

    void testMidiIn() {
        if (midiDevice == null) {
            if (isConnecting) {
                logger.log("Still connecting...");
                handler.post(new Runnable() {
                    @Override
                    public void run() {
                        testMidiIn();
                    }
                });
            } else {
                logger.log("MIDI device is not open!");
                if (testStateListener != null) testStateListener.onTestStoppedWithError();
            }
            return;
        }
        try {
            setupMidiIn();
        } catch (IOException e) {
            logger.log("Error setting up test: " + e.getMessage());
            if (testStateListener != null) testStateListener.onTestStoppedWithError();
            return;
    }

    private void setupMidiOut() throws IOException {
        mInputPort = mMidiDevice.openInputPort(0);

        clockManager.syncClock();
        clockManager.command(ClockManager.CMD_MIDI);
        clockManager.startListener();
        clockManager.setTriggerHandler(triggerHandler);
    }

    private void findMidiDevice() {
    }

    private void findMidiDevice() {
        MidiDeviceInfo[] infos = midiManager.getDevices();
        for(MidiDeviceInfo info : infos) {
            String name = info.getProperties().getString(MidiDeviceInfo.PROPERTY_NAME);
            logger.log("Found MIDI device named " + name);
            if(TEENSY_MIDI_NAME.equals(name)) {
                logger.log("^^^ using this device ^^^");
                isConnecting = true;
                midiManager.openDevice(info, new MidiManager.OnDeviceOpenedListener() {
                    @Override
                    public void onDeviceOpened(MidiDevice device) {
                        if (device == null) {
                            logger.log("Error, unable to open MIDI device");
                        } else {
                            logger.log("Opened MIDI device successfully!");
                            midiDevice = device;
                        }
                        isConnecting = false;
                    }
                }, null);
                break;
            }
        }
    }

    private WaltDevice.TriggerHandler triggerHandler = new WaltDevice.TriggerHandler() {
        @Override

            logger.log(String.format(Locale.US, "Note detected: latency of %.3f ms", dt));

            finishMidiOut();
        }
    };

    private void scheduleNote() {
        if(mInputPort == null) {
            logger.log("mInputPort is not open");
            return;
        }
        long t = System.nanoTime() + noteDelay * 1000 * 1000;
        try {
            mInputPort.send(noteMsg, 0, noteMsg.length, t);
        } catch(IOException e) {
            logger.log("Unable to schedule note: " + e.getMessage());
            return;
        long t = System.nanoTime() + ((long) noteDelay) * 1000000L;
        try {
            // TODO: only schedule some, then sync clock
            for (int i = 0; i < outputRepetitions; i++) {
                midiInputPort.send(noteMsg, 0, noteMsg.length, t + ((long) noteDelay) * 1000000L * i);
        logger.log("All notes detected");
        handler.removeCallbacks(cancelMidiOutRunnable);

        teardownMidiOut();
    }

        logger.log("All notes detected");
        logger.log(String.format(
                Locale.US, "Median total output latency %.1f ms", Utils.median(deltasOutputTotal)));

        handler.removeCallbacks(cancelMidiOutRunnable);

        if (resultHandler != null) {
            resultHandler.onResult(deltasOutputTotal);
        }
        if (testStateListener != null) testStateListener.onTestStopped();
        if (traceLogger != null) traceLogger.flush(context);
        teardownMidiOut();
    }

    private Runnable cancelMidiOutRunnable = new Runnable() {
        @Override
        public void run() {
            logger.log("Timed out waiting for notes to be detected by WALT");
            if (testStateListener != null) testStateListener.onTestStoppedWithError();
            teardownMidiOut();
        }
    };

    private void teardownMidiOut() {
        try {
            midiInputPort.close();
        } catch(IOException e) {
            logger.log("Error, failed to close input port: " + e.getMessage());
        }

        waltDevice.stopListener();
        waltDevice.clearTriggerHandler();
        waltDevice.checkDrift();
    }

    private Runnable requestNoteRunnable = new Runnable() {
        @Override
        public void run() {
            logger.log("Requesting note from WALT...");
            String s;
            try {
                s = waltDevice.command(WaltDevice.CMD_NOTE);
            } catch (IOException e) {
                logger.log("Error sending NOTE command: " + e.getMessage());
                if (testStateListener != null) testStateListener.onTestStoppedWithError();
                return;
            }
            last_tWalt = Integer.parseInt(s);
            handler.postDelayed(finishMidiInRunnable, timeout);
        }
    };

    private Runnable finishMidiInRunnable = new Runnable() {
        @Override
        public void run() {
            waltDevice.checkDrift();

            logger.log("deltas: " + deltasToSys.toString());
            logger.log("MIDI Input Test Results:");
            logger.log(String.format(Locale.US,
                    "Median MIDI subsystem latency %.1f ms\nMedian total latency %.1f ms",
                    Utils.median(deltasToSys), Utils.median(deltasInputTotal)
            ));

            if (resultHandler != null) {
                resultHandler.onResult(deltasToSys, deltasInputTotal);
            }
            if (testStateListener != null) testStateListener.onTestStopped();
            if (traceLogger != null) traceLogger.flush(context);
            teardownMidiIn();
                deltasTotal.add(dt);

                mRepetitionsDone++;
                if (mRepetitionsDone % syncAfterRepetitions == 0) {
                    try {
                        clockManager.syncClock();
                    } catch (IOException e) {
                handler.removeCallbacks(finishMidiInRunnable);
                last_tJava = waltDevice.clock.micros();
                        return;
                    }
                }
                if (mRepetitionsDone < mRepetitions) {
                    handler.post(requestNoteRunnable);
                } else {
                    handler.post(finishMidiInRunnable);
                                "Total = %.3f ms",
                        d1, d2, dt));
                deltasToSys.add(d1);
                deltasInputTotal.add(dt);
                if (testStateListener != null) {
                    handler.post(new Runnable() {
                        @Override
                        public void run() {
                            testStateListener.onTestPartialResult(dt);
                        }
                    });
                }
                if (traceLogger != null) {
                    traceLogger.log(last_tWalt + waltDevice.clock.baseTime,
                            last_tSys + waltDevice.clock.baseTime, "MIDI Input Subsystem",
                            "Bar starts when WALT sends note and ends when received by MIDI subsystem");
                    traceLogger.log(last_tSys + waltDevice.clock.baseTime,
                            last_tJava + waltDevice.clock.baseTime, "MIDI Input Java",
                            "Bar starts when note received by MIDI subsystem and ends when received by app");
                }

                repetitionsDone++;
                if (repetitionsDone % inputSyncAfterRepetitions == 0) {
                    try {
                        waltDevice.syncClock();
                    } catch (IOException e) {
                        logger.log("Error syncing clocks: " + e.getMessage());
                        handler.post(finishMidiInRunnable);
                        return;
                    }
                }
                if (repetitionsDone < inputRepetitions) {
                    handler.post(requestNoteRunnable);
                } else {
                    handler.post(finishMidiInRunnable);
                }
            } else {
                logger.log(String.format(Locale.US, "Expected 0x90, got 0x%x and count was %d",
                        data[offset], count));
            }
        }
    }

    private void setupMidiIn() throws IOException {
        repetitionsDone = 0;
        deltasInputTotal.clear();
        deltasOutputTotal.clear();
        midiOutputPort = midiDevice.openOutputPort(0);
        midiOutputPort.connect(new WaltReceiver());
        waltDevice.syncClock();
    }

    private void teardownMidiIn() {
        handler.removeCallbacks(requestNoteRunnable);
        handler.removeCallbacks(finishMidiInRunnable);
        try {
            midiOutputPort.close();
        } catch (IOException e) {
            logger.log("Error, failed to close output port: " + e.getMessage());
        }
    }
}

<MSG> Add automated and repeated MIDI output testing

<DFF> @@ -54,8 +54,9 @@ class MidiTest {
     private long last_tSys = 0;
     private long last_tJava = 0;
 
-    private static int syncAfterRepetitions = 100;
-    private int mRepetitions = 50;
+    private int mInputSyncAfterRepetitions = 100;
+    private int mOutputSyncAfterRepetitions = 20; // TODO: implement periodic clock sync for output
+    private int mInputRepetitions = 100, mOutputRepetitions = 10;
     private int mRepetitionsDone;
     private ArrayList<Double> deltasToSys = new ArrayList<>();
     private ArrayList<Double> deltasTotal = new ArrayList<>();
@@ -75,8 +76,12 @@ class MidiTest {
         this.resultHandler = resultHandler;
     }
 
-    void setRepetitions (int repetitions) {
-        mRepetitions = repetitions;
+    void setInputRepetitions(int repetitions) {
+        mInputRepetitions = repetitions;
+    }
+
+    void setOutputRepetitions(int repetitions) {
+        mOutputRepetitions = repetitions;
     }
 
     void testMidiOut() {
@@ -100,8 +105,7 @@ class MidiTest {
             logger.log("Error setting up test: " + e.getMessage());
             return;
         }
-        scheduleNote();
-        handler.postDelayed(cancelMidiOutRunnable, noteDelay + timeout);
+        handler.postDelayed(cancelMidiOutRunnable, noteDelay * mInputRepetitions + timeout);
     }
 
     void testMidiIn() {
@@ -129,12 +133,17 @@ class MidiTest {
     }
 
     private void setupMidiOut() throws IOException {
+        mRepetitionsDone = 0;
+        deltasTotal.clear();
+
         mInputPort = mMidiDevice.openInputPort(0);
 
         clockManager.syncClock();
         clockManager.command(ClockManager.CMD_MIDI);
         clockManager.startListener();
         clockManager.setTriggerHandler(triggerHandler);
+
+        scheduleNotes();
     }
 
     private void findMidiDevice() {
@@ -170,18 +179,32 @@ class MidiTest {
 
             logger.log(String.format(Locale.US, "Note detected: latency of %.3f ms", dt));
 
-            finishMidiOut();
+            last_tSys += noteDelay * 1000;
+            mRepetitionsDone++;
+
+            if (mRepetitionsDone < mOutputRepetitions) {
+                try {
+                    clockManager.command(ClockManager.CMD_MIDI);
+                } catch (IOException e) {
+                    logger.log("Failed to send command CMD_MIDI: " + e.getMessage());
+                }
+            } else {
+                finishMidiOut();
+            }
         }
     };
 
-    private void scheduleNote() {
+    private void scheduleNotes() {
         if(mInputPort == null) {
             logger.log("mInputPort is not open");
             return;
         }
-        long t = System.nanoTime() + noteDelay * 1000 * 1000;
+        long t = System.nanoTime() + ((long) noteDelay) * 1000000L;
         try {
-            mInputPort.send(noteMsg, 0, noteMsg.length, t);
+            // TODO: only schedule some, then sync clock
+            for (int i = 0; i < mOutputRepetitions; i++) {
+                mInputPort.send(noteMsg, 0, noteMsg.length, t + ((long) noteDelay) * 1000000L * i);
+            }
         } catch(IOException e) {
             logger.log("Unable to schedule note: " + e.getMessage());
             return;
@@ -193,6 +216,9 @@ class MidiTest {
         logger.log("All notes detected");
         handler.removeCallbacks(cancelMidiOutRunnable);
 
+        if (resultHandler != null) {
+            resultHandler.onResult(deltasTotal);
+        }
         teardownMidiOut();
     }
 
@@ -269,7 +295,7 @@ class MidiTest {
                 deltasTotal.add(dt);
 
                 mRepetitionsDone++;
-                if (mRepetitionsDone % syncAfterRepetitions == 0) {
+                if (mRepetitionsDone % mInputSyncAfterRepetitions == 0) {
                     try {
                         clockManager.syncClock();
                     } catch (IOException e) {
@@ -278,7 +304,7 @@ class MidiTest {
                         return;
                     }
                 }
-                if (mRepetitionsDone < mRepetitions) {
+                if (mRepetitionsDone < mInputRepetitions) {
                     handler.post(requestNoteRunnable);
                 } else {
                     handler.post(finishMidiInRunnable);

Add automated and repeated MIDI output testing