---------- Forwarded message ----------
From: Andreas Raab <[EMAIL PROTECTED]>
Date: 24 juil. 2007 09:45
Subject: Delay and Server reliability
To: The general-purpose Squeak developers list
<[EMAIL PROTECTED]>
Hi -
We recently had some "fun" chasing server lockups (with truly awful
uptimes of about a day or less before things went downhill) and were
finally able to track a huge portion of it down to problems with Delay.
The effect we were seeing on our servers was that the system would
randomly lock up and either go down to 0% CPU or 100% CPU.
After poking it with a USR1 signal (which, in our VMs is hooked up such
that it prints all the call stacks in the image; it's a life-safer if
you need to debug these issues) we usually found that all processes were
waiting on Delay's AccessProtect (0%) or alternatively found that a
particular process (the event tickler) would sit in a tight loop
swallowing repeated errors complaining that "this delay is already
scheduled".
After hours and hours of testing, debugging, and a little stroke of luck
we finally found out that all of these issues were caused by the fact
that Delay's internal structures are updated by the calling process
(insertion into and removal from SuspendedDelays) which renders the
process susceptible to being terminated in the midst of updating these
structures.
If you look at the code, this is obviously an issue because if (for
example) the calling process gets terminated while it's resorting
SuspendedDelays the result is unpredictable. This is in particular an
issue because the calling process is often running at a relatively low
priority so interruption by other, high-priority processes is a common
case. And if any of these higher priority processes kills the one that
just happens to execute SortedCollection>>remove: anything can happen -
from leaving a later delay in front of an earlier one (one of the cases
we had indicated that this was just what had happened) to errors when
doing the next insert/remove ("trying to evaluate a block that is
already evaluated") to many more weirdnesses. Unfortunately, it is
basically impossible to recreate this problem under any kind of
controlled circumstances, mostly because you need a source of events
that is truly independent from your time source.
As a consequence of our findings we rewrote Delay to deal with these
issues properly and, having deployed the changes about ten days ago on
our servers, all of these sources of problems simply vanished. We
haven't had a single server problem which we couldn't attribute to our
own stupidity (such as running out of disk space ;-)
The changes will in particular be helpful to you if you:
* run network servers
* fork processes to handle network requests
* terminate these processes explicitly (on error conditions for example)
* use Semaphore>>waitTimeoutMsecs: (all socket functions use this)
If you have seen random, unexplained lockups of your server (0% CPU load
while being locked up is a dead giveaway[*]) I'd recommend using the
attached changes (which work best on top of a VM with David Lewis' 64bit
fixes applied) and see if that helps. For us, they made the difference
between running the server in Squeak and rewriting it in Java.
I've also filed this as http://bugs.squeak.org/view.php?id=6576
[*] The 0% CPU lockups have sometimes been attributed to issues with
Linux wait functions. After having seen the havoc that Delay wrecks on
the system I don't buy these explanations any longer. A much simpler
(and more likely) explanation is that Delay went wild.
Cheers,
- Andreas
--
Damien Cassou
'From Croquet1.0beta of 11 April 2006 [latest update: #1] on 23 July 2007 at 11:53:23 pm'!
"Change Set: SafeDelay
Date: 23 July 2007
Author: Andreas Raab
This change set fixes a set of severe problems with concurrent use of Delay. Previously, many of the delay-internal structures were modified by the calling process which made it susceptible to being terminated in the middle of manipulating these structures and leave Delay (and consequently the entire system) in an inconsistent state.
This change set fixes this problem by moving *all* manipulation of Delay's internal structures out of the calling process. As a side-effect it also removes the requirement of Delays being limited to SmallInteger range; the new code has no limitation on the duration of a delay.
No tests are provided since outside of true asynchronous environments (networks) it is basically impossible to recreate the situation reliably."!
!Delay methodsFor: 'private' stamp: 'ar 7/10/2007 21:24'!
activate
"Private!! Make the receiver the Delay to be awoken when the next timer interrupt occurs. This method should only be called from a block protected by the AccessProtect semaphore."
TimerEventLoop ifNotNil:[^nil].
ActiveDelay := self.
ActiveDelayStartTime := Time millisecondClockValue.
ActiveDelayStartTime > resumptionTime ifTrue:[
ActiveDelay signalWaitingProcess.
SuspendedDelays isEmpty ifTrue:[
ActiveDelay := nil.
ActiveDelayStartTime := nil.
] ifFalse:[SuspendedDelays removeFirst activate].
] ifFalse:[
TimingSemaphore initSignals.
Delay primSignal: TimingSemaphore atMilliseconds: resumptionTime.
].! !
!Delay methodsFor: 'private' stamp: 'ar 7/10/2007 21:55'!
schedule
"Private!! Schedule this Delay, but return immediately rather than waiting. The receiver's semaphore will be signalled when its delay duration has elapsed."
beingWaitedOn ifTrue: [self error: 'This Delay has already been scheduled.'].
TimerEventLoop ifNotNil:[^self scheduleEvent].
AccessProtect critical: [
beingWaitedOn := true.
resumptionTime := Time millisecondClockValue + delayDuration.
ActiveDelay == nil
ifTrue: [self activate]
ifFalse: [
resumptionTime < ActiveDelay resumptionTime
ifTrue: [
SuspendedDelays add: ActiveDelay.
self activate]
ifFalse: [SuspendedDelays add: self]]].
! !
!Delay methodsFor: 'private' stamp: 'ar 7/10/2007 22:33'!
scheduleEvent
"Schedule this delay"
resumptionTime := Time millisecondClockValue + delayDuration.
AccessProtect critical:[
ScheduledDelay := self.
TimingSemaphore signal.
].! !
!Delay methodsFor: 'private' stamp: 'ar 7/10/2007 21:55'!
unschedule
"Unschedule this Delay. Do nothing if it wasn't scheduled."
| done |
TimerEventLoop ifNotNil:[^self unscheduleEvent].
AccessProtect critical: [
done := false.
[done] whileFalse:
[SuspendedDelays remove: self ifAbsent: [done := true]].
ActiveDelay == self ifTrue: [
SuspendedDelays isEmpty
ifTrue: [
ActiveDelay := nil.
ActiveDelayStartTime := nil]
ifFalse: [
SuspendedDelays removeFirst activate]]].
! !
!Delay methodsFor: 'private' stamp: 'ar 7/10/2007 21:56'!
unscheduleEvent
AccessProtect critical:[
FinishedDelay := self.
TimingSemaphore signal.
].! !
!Delay methodsFor: 'public' stamp: 'ar 7/10/2007 21:49'!
beingWaitedOn
"Answer whether this delay is currently scheduled, e.g., being waited on"
^beingWaitedOn! !
!Delay methodsFor: 'public' stamp: 'ar 7/10/2007 21:49'!
beingWaitedOn: aBool
"Indicate whether this delay is currently scheduled, e.g., being waited on"
beingWaitedOn := aBool! !
!Delay methodsFor: 'public' stamp: 'ar 7/10/2007 20:56'!
delayDuration
^delayDuration! !
!Delay class methodsFor: 'timer process' stamp: 'ar 7/11/2007 10:35'!
handleTimerEvent
"Handle a timer event; which can be either:
- a schedule request (ScheduledDelay notNil)
- an unschedule request (FinishedDelay notNil)
- a timer signal (not explicitly specified)
We check for timer expiry every time we get a signal."
| nextTick |
"Wait until there is work to do."
TimingSemaphore wait.
"Process any schedule requests"
ScheduledDelay ifNotNil:[
"Schedule the given delay"
self scheduleDelay: ScheduledDelay.
ScheduledDelay := nil.
].
"Process any unschedule requests"
FinishedDelay ifNotNil:[
self unscheduleDelay: FinishedDelay.
FinishedDelay := nil.
].
"Check for clock wrap-around."
nextTick := Time millisecondClockValue.
nextTick < ActiveDelayStartTime ifTrue: [
"clock wrapped"
self saveResumptionTimes.
self restoreResumptionTimes.
].
ActiveDelayStartTime := nextTick.
"Signal any expired delays"
[ActiveDelay notNil and:[
Time millisecondClockValue >= ActiveDelay resumptionTime]] whileTrue:[
ActiveDelay signalWaitingProcess.
SuspendedDelays isEmpty
ifTrue: [ActiveDelay := nil]
ifFalse:[ActiveDelay := SuspendedDelays removeFirst].
].
"And signal when the next request is due. We sleep at most 1sec here
as a soft busy-loop so that we don't accidentally miss signals."
nextTick := Time millisecondClockValue + 1000.
ActiveDelay ifNotNil:[nextTick := nextTick min: ActiveDelay resumptionTime].
nextTick := nextTick min: SmallInteger maxVal.
"Since we have processed all outstanding requests, reset the timing semaphore so
that only new work will wake us up again. Do this RIGHT BEFORE setting the next
wakeup call from the VM because it is only signaled once so we mustn't miss it."
TimingSemaphore initSignals.
Delay primSignal: TimingSemaphore atMilliseconds: nextTick.
! !
!Delay class methodsFor: 'timer process' stamp: 'ar 7/11/2007 09:04'!
runTimerEventLoop
"Run the timer event loop."
[
[RunTimerEventLoop] whileTrue: [self handleTimerEvent]
] on: Error do:[:ex|
"Clear out the process so it does't get killed"
TimerEventLoop := nil.
"Launch the old-style interrupt watcher"
self startTimerInterruptWatcher.
"And pass the exception on"
ex pass.
].! !
!Delay class methodsFor: 'timer process' stamp: 'ar 7/10/2007 22:32'!
scheduleDelay: aDelay
"Private. Schedule this Delay."
aDelay beingWaitedOn: true.
ActiveDelay ifNil:[
ActiveDelay := aDelay
] ifNotNil:[
aDelay resumptionTime < ActiveDelay resumptionTime ifTrue:[
SuspendedDelays add: ActiveDelay.
ActiveDelay := aDelay.
] ifFalse: [SuspendedDelays add: aDelay].
].
! !
!Delay class methodsFor: 'timer process' stamp: 'ar 7/11/2007 10:18'!
startTimerEventLoop
"Start the timer event loop"
"Delay startTimerEventLoop"
self stopTimerEventLoop.
self stopTimerInterruptWatcher.
AccessProtect := Semaphore forMutualExclusion.
ActiveDelayStartTime := Time millisecondClockValue.
SuspendedDelays :=
Heap withAll: (SuspendedDelays ifNil:[#()])
sortBlock: [:d1 :d2 | d1 resumptionTime <= d2 resumptionTime].
TimingSemaphore := Semaphore new.
RunTimerEventLoop := true.
TimerEventLoop := [self runTimerEventLoop] newProcess.
TimerEventLoop priority: Processor timingPriority.
TimerEventLoop resume.
TimingSemaphore signal. "get going"
! !
!Delay class methodsFor: 'timer process' stamp: 'ar 7/10/2007 22:32'!
startTimerInterruptWatcher
"Reset the class variables that keep track of active Delays and re-start the timer interrupt watcher process. Any currently scheduled delays are forgotten."
"Delay startTimerInterruptWatcher"
| p |
self stopTimerEventLoop.
self stopTimerInterruptWatcher.
TimingSemaphore := Semaphore new.
AccessProtect := Semaphore forMutualExclusion.
SuspendedDelays :=
SortedCollection sortBlock:
[:d1 :d2 | d1 resumptionTime <= d2 resumptionTime].
ActiveDelay := nil.
p := [self timerInterruptWatcher] newProcess.
p priority: Processor timingPriority.
p resume.
! !
!Delay class methodsFor: 'timer process' stamp: 'ar 7/10/2007 21:26'!
stopTimerEventLoop
"Stop the timer event loop"
RunTimerEventLoop := false.
TimingSemaphore signal.
TimerEventLoop := nil.! !
!Delay class methodsFor: 'timer process' stamp: 'ar 7/10/2007 21:32'!
stopTimerInterruptWatcher
"Reset the class variables that keep track of active Delays and re-start the timer interrupt watcher process. Any currently scheduled delays are forgotten."
"Delay startTimerInterruptWatcher"
self primSignal: nil atMilliseconds: 0.
TimingSemaphore ifNotNil:[TimingSemaphore terminateProcess].! !
!Delay class methodsFor: 'timer process' stamp: 'ar 7/10/2007 22:33'!
unscheduleDelay: aDelay
"Private. Unschedule this Delay."
ActiveDelay == aDelay ifTrue: [
SuspendedDelays isEmpty ifTrue:[
ActiveDelay := nil.
] ifFalse: [
ActiveDelay := SuspendedDelays removeFirst.
]
] ifFalse:[
SuspendedDelays remove: aDelay ifAbsent: [].
].
aDelay beingWaitedOn: false.! !
!Delay class methodsFor: 'class initialization' stamp: 'ar 7/11/2007 18:16'!
initialize
"Delay initialize"
self startTimerEventLoop.! !
Delay initialize!
_______________________________________________
V3dot10 mailing list
[email protected]
http://lists.squeakfoundation.org/mailman/listinfo/v3dot10
