Comment 3 for bug 1728902

Revision history for this message
John A Meinel (jameinel) wrote :

All of the ones that don't have m=+ seem to be exactly 30s later than the current timestamp.
15:47:52.716 ... 11:48:22.725722344
15:48:22.761 ... 11:48:52.767118576
15:48:52.803 ... 11:49:22.81749278
15:49:22.854 ... 11:49:52.871913825

Compare that with the other ones:
15:47:52.815 ... 11:48:52.767118576 m=...
15:47:52.850 ... 11:48:52.807188433 m=...
15:47:55.139 ... 11:48:55.092921836 m=...
15:48:00.183 ... 11:49:00.183642493 m=...

15:48:22.869 ... 11:49:22.81749278 m=+...
15:48:22.895 ... 11:49:22.852232168 m=...
15:48:25.138 ... 11:49:25.093142689 m=...
15:48:45.746 ... 11:49:45.746100232 m=...

The Hour differences is just because I'm in UTC+4 and debug-log defaults to local times while log entries default to UTC.

But all of those look specifically like 1 min time deltas. That would work with the idea that:
nextTick := now.Add(manager.config.MaxSleep)
  - generates a time.Time object that has monotonic time and
nextTick = info.Expiry
  - does not.

If we actually just go to the ones without m= it does look like we're only waking up at the correct rate:

15:47:52.716 DEBUG ... at 2017-10-31 11:48:22.725722344
15:48:22.761 DEBUG ... at 2017-10-31 11:48:52.767118576
15:48:52.803 DEBUG ... at 2017-10-31 11:49:22.81749278
15:49:22.854 DEBUG ... at 2017-10-31 11:49:52.871913825
15:49:52.909 DEBUG ... at 2017-10-31 11:50:22.923342048
15:50:22.959 DEBUG ... at 2017-10-31 11:50:52.969434594
15:50:53.004 DEBUG ... at 2017-10-31 11:51:23.024836933
15:51:23.057 DEBUG ... at 2017-10-31 11:51:53.079786742
15:51:53.109 DEBUG ... at 2017-10-31 11:52:23.140325923

Those all match up reasonably well at saying "will wake up at" and the next log entry is just slightly after that time.

So the real question is more that while every manager has a list of leases that
it could handle, why are we seeing so many managers operating concurrently when
there are only 2 models.
I wonder if we're not stopping managers correctly. Given that all of those
managers are operating on the MaxSleep polling, that sounds like they're
actually not doing anything. So why are we running them?
Taking it a step further, if they really are all running at 1min, we actually
have 1 Manager that is doing something at 30s poll intervals, but another 9
managers sleeping 1min rotations.