Open taylorlm88 opened 2 years ago
Issue #57 seems to be an extreme case for this -- commands are only executed many seconds after they are sent.
This should already be in the latest builds. You can get the time received for a message in the base tdms file and the time the pattern is played out in the Frame_Time tdms file
The data is now in the TDMS files.
For my understanding, could you clarify the timing of events please?
Let me use one example of the gapsInLogXLSX
function that we shared previously.
Within each loop, there are 6 commands sent to the G4 Host (here the full code within each loop, minor change compared to previously shared code):
testCase.panelsController.startLog()
testCase.panelsController.setPatternID(ii);
testCase.panelsController.setPatternFunctionID(ii);
testCase.panelsController.setPositionX(ii);
startTime = tic;
rsp = testCase.panelsController.startDisplay(23);
seqComplete = toc(startTime);
testCase.panelsController.stopLog();
rsps = [rsps; rsp];
runTime = [runTime; 23];
seqTime = [seqTime; seqComplete];
For the Command Received I get the following timings (last column added by me, difference of current Time to previous line):
Time | Command | Data | time diff |
---|---|---|---|
1419599480 | Set Pattern ID | 3A/1 | NA |
1419599480 | Set Pattern Function ID | 3A/1 | 0 |
1419601942 | Set-Position X | 3A/1 | 2462 |
1419601942 | Start-Display | 17/0 | 0 |
1421907925 | Stop Log | 2305983 |
For the same trial, the Pattern Position contains the following values (second column added by me):
Time | time diff |
---|---|
1419629800 | NA |
1419631801 | 2001 |
1419633800 | 1999 |
... | ... |
1421923801 | 2001 |
1421925800 | 1999 |
1421927800 | 2000 |
The difference between the timing of the first item in Pattern Position and the last item is 2298000
, which is exactly what I'd expect for an experiment that is supposed to last 2300ms.
I don't fully understand the timing within Command Received, specifically why two commands are received at exactly the same ns, but the command that is on the next line in MATLAB take 2462ns. This might be addressed in issue #52, though.
In this current issue I would like to understand the difference between Command Received and Pattern Position. So the time difference between the Start-Display
command and the first pattern is 27858ns (for other experiments this value is similar between 24000ns and 29000ns). Is my interpretation correct, it takes almost 28ms between sending a Start-Display
and actually starting the display? (Which seems long but acceptable, especially in open-loop conditions. If it is a one-time initialization cost, then it is probably also OK for closed loop conditions.)
Secondly, the difference between the last pattern from the Pattern Position and the Stop-Display
command in the _Command Received is -19875ns (for other experiments this values is similar between 18000ns and 20000ns), that means the Stop-Display
command is sent 20ms before the last frame starts showing (22ms before it is finished). We know that the startDisplay
command in the MATLAB code above receives the confirmation precisely at the right time (that was fixed in #59). It then does the toc
line in MATLAB before sending a stopDisplay
command.
Related to this I have three more related questions:
start-display
command sends the confirmation of being finished while the display itself is still displaying patterns for some more time?start-display
? In this example 2300ms after start-display
was received or 2300ms after having executed the start-display
, which might take about 8000ns according to the delay of stop-display
.
Summary: Log display time as well as communication time.
Description: If possible, we would like to Log the exact time that a pattern appears on the screen. Right now we get the exact time of each TCP command, so we know when the 'start-display' was received. But the frame position data seems to indicate there is some lag time between the start-display command being received and the frame position indicating the new pattern is being displayed. It's hard to get a handle on how long this lag is exactly due to the way frame position is logged described in number 1. If we could, in addition, get information on when the start-display command actually takes effect and the pattern appears on the screen, it would be very helpful to us.