Understanding precision sync - page 2 - General Discussion and Assistance - CHDK Forum
« previous next »
Pages: 1 [2] 3   Go Down

Understanding precision sync

  • 26 Replies
  • 6358 Views
*

Offline andrew.stephens.754365

  • ****
  • 457
Re: Understanding precision sync
« Reply #10 on: 22 / February / 2018, 03:25:47 »
Advertisements
Quote from: philmoz on 21 / February / 2018, 16:46:17
I suspect there is some case where the msleep(40) is not always ensuring the behaviour we are after.


Perhaps playing with the msleep value might give some clues.


Phil.

Ok, thanks.

vnd said of the "critical value" (for S95):

Quote from: vnd on 04 / November / 2012, 13:20:07
I have found that the value 0xe0 which is the phase which causes that the camera waits for the next period instead of shooting immediately is written to register 0xC0F0713C. See the section HEAD Timers here http://magiclantern.wikia.com/wiki/Register_Map. It is also increased in low light live view.

For A1200 with a std_period = 209, this critical value must be less than 209.

If a count of 209 is equivalent to 33ms then a single count = 0.158ms

The minimum extended period count for A1200 is:
2x std period less (std period - curr count) = 2x209 - (209 - 200) = 409, equivalent to 64.58ms.

So long as msleep(40) is greater than an actual delay of 33ms it seems impossible the count at its expiry would be less than 209.

So long as msleep(40) is less than an actual delay of 64.58ms we are still in the extended count when control reverts to Canon which will see a count greater than the critical value and schedule a shot at the end of the subsequent std period.

If msleep(40) is less than an actual delay of 33ms it seems possible the count at its expiry could be less than the critical value - but, my understanding is, that would cause the shot to occur immediately. This would result in an outlier that was not exactly a single period removed from the other precision sync shots (in reality we do not see that result).

If msleep(40) is greater than an actual delay of 65.48ms ... i'm not yet sure sure what to say in those circumstances.


Is it known - is there a reasonable possibility that msleep(40) could, on occasion, be less than actual 33ms or greater than actual 65.48ms?

(will be offline mostly now for next few days) 

Edit:
If msleep(40) is greater than an actual delay of 65.48ms - at expiry, we are likely in the early section of the std period following the extended period. It is therefore likely the count is less than the critical value & the shot will fire immediately. Since the shot is not taken at the end of a post sync period, the outlier will not be one std period (or multiple std periods) removed from the other precision sync shots.

Overall, the tentative conclusion is that the msleep(40) is not the origin of the precision sync outlier.   
« Last Edit: 22 / February / 2018, 04:14:04 by andrew.stephens.754365 »
Logged
*

Offline philmoz

  • *****
  • 3146
    • Photos
Re: Understanding precision sync
« Reply #11 on: 22 / February / 2018, 04:44:51 »
Quote from: andrew.stephens.754365 on 22 / February / 2018, 03:25:47
Quote from: vnd on 04 / November / 2012, 13:20:07
I have found that the value 0xe0 which is the phase which causes that the camera waits for the next period instead of shooting immediately is written to register 0xC0F0713C. See the section HEAD Timers here http://magiclantern.wikia.com/wiki/Register_Map. It is also increased in low light live view.


What I meant was that under some circumstances this does not happen and the shot is taken at the end of the extended period instead of after the following standard period (even after waiting 40ms).
Perhaps the value in 0xC0F0713C is changed by some other logic in the firmware (vnd says it changes in low light, when else might it change?).

Experimenting with the msleep value might shed some light on it, or perhaps log the value of 0xC0F0713C (assuming this is the same register on all cameras).

Phil.
Logged
CHDK ports:
  sx30is (1.00c, 1.00h, 1.00l, 1.00n & 1.00p)
  g12 (1.00c, 1.00e, 1.00f & 1.00g)
  sx130is (1.01d & 1.01f)
  ixus310hs (1.00a & 1.01a)
  sx40hs (1.00d, 1.00g & 1.00i)
  g1x (1.00e, 1.00f & 1.00g)
  g5x (1.00c, 1.01a, 1.01b)
*

Offline andrew.stephens.754365

  • ****
  • 457
Re: Understanding precision sync
« Reply #12 on: 22 / February / 2018, 04:55:00 »
Quote from: philmoz on 22 / February / 2018, 04:44:51
What I meant was that under some circumstances this does not happen and the shot is taken at the end of the extended period instead of after the following standard period (even after waiting 40ms).
Perhaps the value in 0xC0F0713C is changed by some other logic in the firmware (vnd says it changes in low light, when else might it change?).

Experimenting with the msleep value might shed some light on it, or perhaps log the value of 0xC0F0713C (assuming this is the same register on all cameras).

Phil.

Yes, now understood.

Will experiment some in a few days.

Thanks.
Logged
*

Offline philmoz

  • *****
  • 3146
    • Photos
Re: Understanding precision sync
« Reply #13 on: 03 / March / 2018, 01:57:19 »
I have a theory for the outliers happening 30ms before the majority of cases.

After experimenting on my G12 I believe that if the current vsync value (GPIO_VSYNC_CURRENT) is very low when the extended sync period is written to GPIO_VSYNC_MAX then the extended period starts immediately not after the next standard period.

Comparing the current usb_sync.c to vnd's original code I noticed a discrepancy:
Code: [Select]
        if (std_period - cur_cnt < 10)                               // if too close to overflow, wait for the next period
        {
-->         sync_period -= (std_period - cur_cnt);
            while ((*(volatile int*)(GPIO_VSYNC_CURRENT) & 0xffff) >= cur_cnt) {};
        }
was originally
Code: [Select]
        if (std_period - cur_cnt < 10)                               // if too close to overflow, wait for the next period
        {
-->         sync_period -= std_period;
            while ((*(volatile int*)(GPIO_VSYNC_CURRENT) & 0xffff) >= cur_cnt) {};
        }

In the current code the extended period is only being reduced by at most 10 instead of a full standard period. So whenever this case occurs the sync should have been almost a standard period longer; but this does not happen. The only reason I can think of is that after the loop GPIO_VSYNC_CURRENT will be 0 (or perhaps 1) and the extended period occurs immediately.

Recording the number of times this code loops seems to confirm this:
Code: [Select]
        while (*(volatile int*)(GPIO_VSYNC_UPDATE)) {}; // wait until the new value is applied

When GPIO_VSYNC_CURRENT is small when this loop runs, it only runs for a very short time, otherwise it runs for considerably longer.

The code below might help with the outliers (replace lines 99-104 in usb_sync.c)
Code: [Select]
        if (std_period - cur_cnt < 10)                               // if too close to overflow, wait for the next period
        {
            sync_period -= std_period;
            while ((*(volatile int*)(GPIO_VSYNC_CURRENT) & 0xffff) >= cur_cnt) {};
        }

        while ((*(volatile int*)(GPIO_VSYNC_CURRENT) & 0xffff) < 5) {}; // If at very start of period wait a bit to ensure extended period does not start immediately

Phil.
Logged
CHDK ports:
  sx30is (1.00c, 1.00h, 1.00l, 1.00n & 1.00p)
  g12 (1.00c, 1.00e, 1.00f & 1.00g)
  sx130is (1.01d & 1.01f)
  ixus310hs (1.00a & 1.01a)
  sx40hs (1.00d, 1.00g & 1.00i)
  g1x (1.00e, 1.00f & 1.00g)
  g5x (1.00c, 1.01a, 1.01b)
*

Offline andrew.stephens.754365

  • ****
  • 457
Re: Understanding precision sync
« Reply #14 on: 03 / March / 2018, 08:49:38 »
Well spotted Phil.

Quote from: philmoz on 03 / March / 2018, 01:57:19
The only reason I can think of is that after the loop GPIO_VSYNC_CURRENT will be 0 (or perhaps 1) and the extended period occurs immediately.

To be sure I understand:
If this is the case, with the mistake discrepancy (sync_period -= (std_period - cur_cnt) in the build, then, for the items within 9 of the count end at switch release, the sync_period will be nearly 3x std counts. If the extended period begins immediately at, say, GPIO_VSYNC_CURRENT = 1 then at 40ms into the period Canon will see a count greater than the critical value and schedule the shot for the end of the subsequent std period i.e. at total 4x33ms = 132ms from switch release.     

You therefore think waterwingz precision sync test result here:
https://chdk.setepontos.com/index.php?topic=8312.msg107601#msg107601

was without the mistake discrepancy in the build, i.e, that test actually used:
Code: [Select]
sync_period -= std_period
in which the sync_period was nearly 2x std counts and the outliers occurred at the end of the subsequent std period at approx 99ms from switch release?

Your suggestion sounds good - i'll try it out soon.

Thanks.

Edit:

PS

Quote from: philmoz on 03 / March / 2018, 01:57:19

Recording the number of times this code loops seems to confirm this:
Code: [Select]
        while (*(volatile int*)(GPIO_VSYNC_UPDATE)) {}; // wait until the new value is applied


When GPIO_VSYNC_CURRENT is small when this loop runs, it only runs for a very short time, otherwise it runs for considerably longer.


Can you provide code you used to record that?


fmi:
http://subversion.assembla.com/svn/chdk/trunk/core/usb_sync.c
 
« Last Edit: 05 / March / 2018, 02:56:20 by andrew.stephens.754365 »
Logged
*

Offline philmoz

  • *****
  • 3146
    • Photos
Re: Understanding precision sync
« Reply #15 on: 03 / March / 2018, 16:49:13 »
Quote from: andrew.stephens.754365 on 03 / March / 2018, 08:49:38
Well spotted Phil.

Quote from: philmoz on 03 / March / 2018, 01:57:19
The only reason I can think of is that after the loop GPIO_VSYNC_CURRENT will be 0 (or perhaps 1) and the extended period occurs immediately.

To be sure I understand:
If this is the case, with the mistake discrepancy (sync_period -= (std_period - cur_cnt) in the build, then, for the items within 9 of the count end at switch release, the sync_period will be nearly 3x std counts. If the extended period begins immediately at, say, GPIO_VSYNC_CURRENT = 1 then at 40ms into the period Canon will see a count greater than the critical value and schedule the shot for the end of the subsequent std period i.e. at total 4x33ms = 132ms from switch release.     

You therefore think waterwingz precision sync test result here:
https://chdk.setepontos.com/index.php?topic=8312.msg107601#msg107601

was without the mistake discrepancy in the build, i.e, that test actually used:
Code: [Select]
sync_period -= std_period
in which the sync_period was nearly 2x std counts and the outliers occurred at the end of the subsequent std period at approx 99ms from switch release?

I think waterwingz used the code currently in SVN.
My theory is that there are three cases to deal with when the USB remote is triggered:

1. cur_cnt very small (e.g. < 5) [start of period, this is the case not handled by the SVN code]
2. std_period - cur_cnt < 10 [end of period]
3. everything else

In case 3 the extended period (2 * std_period + cur_cnt) is written to GPIO_VSYNC_MAX straight away and begins after the end of the current period.
In case 2 the theory was to wait for the end of the current period then write an extended period of 1 * std_period + cur_cnt to GPIO_VSYNC_MAX. This extended period was not expected to start until the end of the new standard period we just entered (so the total would still be 2 * std_period + cur_cnt).
Case 1 was not in the current code.

In reality case 2 is writing 2 * std_period + cur_cnt - (std_period - cur_cnt) to GPIO_VSYNC_MAX. Since std_period - cur_cnt < 10 the value is at most only 9 less than case 3. On my G12 std_period is 272 so 9 / 272 * 33ms = 1ms - too small to measure accurately or have any real effect.

If case 2 were indeed starting after the end of the new period we waited for, then it would result in the shot being nearly 1 std_period too late; but that doesn't happen.

Hence case 1 above - this occurs after case 2 and also randomly when the USB remote is triggered. The new sync_period is written immediately which explains why case 2 is never late. It also explains the outliers which occur when cur_cnt is very small when the remote triggers (current period becomes the extended period).

Finally i don't think the msleep(40) has any effect on the final shot time, although I don't have an accurate method to measure like waterwingz does. I played with the sleep time and even removed the sleep altogether and it did not seem to make any difference.

Further testing shows that the msleep(40) is needed to ensure consistent timing.

Quote
Quote from: philmoz on 03 / March / 2018, 01:57:19

Recording the number of times this code loops seems to confirm this:
Code: [Select]
        while (*(volatile int*)(GPIO_VSYNC_UPDATE)) {}; // wait until the new value is applied


When GPIO_VSYNC_CURRENT is small when this loop runs, it only runs for a very short time, otherwise it runs for considerably longer.

Can you provide code you used to record that?


Attached is a patch with the diagnostics I added to try and trace what is happening.

Phil.
« Last Edit: 03 / March / 2018, 18:11:45 by philmoz »
Logged
CHDK ports:
  sx30is (1.00c, 1.00h, 1.00l, 1.00n & 1.00p)
  g12 (1.00c, 1.00e, 1.00f & 1.00g)
  sx130is (1.01d & 1.01f)
  ixus310hs (1.00a & 1.01a)
  sx40hs (1.00d, 1.00g & 1.00i)
  g1x (1.00e, 1.00f & 1.00g)
  g5x (1.00c, 1.01a, 1.01b)
*

Offline philmoz

  • *****
  • 3146
    • Photos
Re: Understanding precision sync
« Reply #16 on: 03 / March / 2018, 18:32:49 »
If my theory is correct in the previous posts, then the case 2 logic (where std_period - cur_cnt < 10) is redundant.

If the extended period is initiated immediately when we are at the very start of a period then it doesn't matter if GPIO_VSYNC_CURRENT overflows while we are doing our calculations. The only special case we need to worry about is when cur_cnt is very small.

Code: [Select]
        int sync_period = std_period * 2 + cur_cnt;                  // schedule the end of extended period at t = t(synch pulse) + sync_time

        if (cur_cnt < 5)
        {
            while ((*(volatile int*)(GPIO_VSYNC_CURRENT) & 0xffff) < 5) {}; // If at very start of period wait a bit to ensure extended period does not start immediately
        }

        *(volatile int*)(GPIO_VSYNC_MAX) = sync_period; // write the length of the extended period to the register
        *(volatile int*)(GPIO_VSYNC_UPDATE) = 1;

I don't have the setup to validate this unfortunately.

Phil.

Logged
CHDK ports:
  sx30is (1.00c, 1.00h, 1.00l, 1.00n & 1.00p)
  g12 (1.00c, 1.00e, 1.00f & 1.00g)
  sx130is (1.01d & 1.01f)
  ixus310hs (1.00a & 1.01a)
  sx40hs (1.00d, 1.00g & 1.00i)
  g1x (1.00e, 1.00f & 1.00g)
  g5x (1.00c, 1.01a, 1.01b)
*

Offline andrew.stephens.754365

  • ****
  • 457
Re: Understanding precision sync
« Reply #17 on: 04 / March / 2018, 04:47:30 »
Quote from: philmoz on 03 / March / 2018, 18:32:49
If the extended period is initiated immediately when we are at the very start of a period then it doesn't matter if GPIO_VSYNC_CURRENT overflows while we are doing our calculations. The only special case we need to worry about is when cur_cnt is very small.

Understood.

Using CRT tester a few months ago, of 490 stereo pairs on SX150IS (std_period = 620) there were 3 outliers (0.61%).

When I get a chance I will repeat that test and report back here.

Although I have no way of testing for absolute time, if there are no outliers in the results, it would seem safe to assume a period of 4xstd_periods between switch release and shots in all cases.

Thanks again.
Logged
*

Offline andrew.stephens.754365

  • ****
  • 457
Re: Understanding precision sync
« Reply #18 on: 09 / March / 2018, 09:33:39 »
With the new code I recorded 1019 stereo pairs.

Having input data (attached) to the CRT tester spreadsheet there is no occurrence of the single period outlier.

GPIO_VSYNC_MAX & GPIO_VSYNC_CURRENT were recorded immediately after switch release for (most) images (slight glitch caused that) and is also available in the spreadsheet detail.

The summary data is:

Minimum Mis-Sync (ms):     0.00        Average Mis-Sync (ms):    0.13
Maximum Mis-Sync (ms):    7.57        Average Deviation:           0.13

Abs. mis-sync(ms)   Count Occurrence
7.57                        1
2.18                        1
2.07                        1
1.97                        1
1.87                        1
1.56                        2
1.24                        1
1.14                        3
1.04                        3
0.93                        4
0.83                        6
0.73                        1
0.62                        7
0.52                        8
0.41                        25
0.39                        1
0.31                        30
0.21                        148
0.1                          352
0                             423

Grand Total            1019
« Last Edit: 09 / March / 2018, 15:23:11 by andrew.stephens.754365 »
Logged
*

Offline andrew.stephens.754365

  • ****
  • 457
Re: Understanding precision sync
« Reply #19 on: 18 / March / 2018, 10:05:53 »
Edit (30 Nov 2018):
all comments below the double horizontal rule here were made before realising that vnd's precision sync code was added to chdk trunk in 2014.

The entire comment is probably misleading so probably best to ignore but will leave in place for the record only. 

Of passing interest - it struck me recently that the "normal sync" results obtained in a 2015 test of 88 SX150IS stereo pairs here https://chdk.setepontos.com/index.php?topic=6953.msg120316#msg120316
were, probably, the equivalent of "pre critical count" precision sync.

Those results:

Abs. mis-sync(ms)   Count Occurrence
5.09                         1
2.29                         1
2.18                         2
1.98                         1
1.87                         1
1.66                         1
1.56                         2
1.25                         2
0.73                         1
0.42                         1
0.31                         2
0.21                         20
0.1                           23
0                              30

Grand Total              88

Since GPIO_TICKS_TO_INTERRUPT 0xC0F0713C is 541 (normal std period = 620) then 541/620 = 87.23%, it seems all current counts were probably less than 541 at switch release and the shots occurred (nearly) immediately (otherwise variances greater than 33ms would have occurred).

Edit:
I didn't (and still don't) have a way to determine if there was any delay between switch release and the non precision sync results reported (I assume it was practically zero) but don't currently understand why most of the non-precision sync A1200 shots did not occur nearly immediately after switch release and why it's normal sync is seemingly much worse than that of SX150IS (unless, perhaps, the ratio of its critical value to normal std_period is much smaller).

Edit2:
looking at the diagram for A1200 again - perhaps the critical value is very early in the std_period and the switch release occurred after that value in all sample cases - hence the reason for all shots occurring at least 33ms after switch release. For those which occurred at nearly 2 xstd_periods after switch release (assuming std_period = 33ms) they had, perhaps, just passed the very early critical value at switch release.   
« Last Edit: 30 / November / 2018, 08:03:53 by andrew.stephens.754365 »
Logged
Pages: 1 [2] 3   Go Up
« previous next »
 

Related Topics