[Vm-dev] Intermittent AttachableFileStream error during 7:36 and 10:36 today

Thu May 20 08:53:35 UTC 2021

Maybe not related at all, but in a different context we were getting
random failures when redirecting output from os commands to the stdio
depending on the value of #ioMSecs caused by an inconsistency in how
globalSessionID was computed
(https://github.com/pharo-project/opensmalltalk-vm/issues/233)

On Wed, May 19, 2021 at 11:28 PM Bob Westergaard <bwestergaard at gmail.com> wrote:
>
>
> I'm pretty sure that is it.  I added some logging code to primitiveTestEndOfFileFlag() and the session ids do not compare.  I see (in a not very recent) VMMaker image that #ioMSecs is used to create the global session id.  Maybe there is some overflow/underflow with the primitive type used for this field?
>
> -- Bob
>
> On Wed, May 19, 2021 at 2:17 PM Bob Westergaard <bwestergaard at gmail.com> wrote:
>>
>> I wonder if the file/pipe sessionID comparison with the getThisSessionID() that is failing in a primitive somewhere.    I guess I'll look at how that is created.
>>
>> -- Bob
>>
>> On Wed, May 19, 2021 at 2:06 PM Bob Westergaard <bwestergaard at gmail.com> wrote:
>>>
>>>
>>> Hi Dave,
>>>
>>> I'm changing the system time before starting the image.
>>>
>>> -- Bob
>>>
>>> On Wed, May 19, 2021 at 2:02 PM David T. Lewis <lewis at mail.msen.com> wrote:
>>>>
>>>>
>>>> Wos, that's a new one on me. What exactly are you changing on your
>>>> computer, are you changing the system time, or changing time zone?
>>>>
>>>> Dave
>>>>
>>>> On Wed, May 19, 2021 at 12:17:58PM -0700, Bob Westergaard wrote:
>>>> >
>>>> > Hi,
>>>> >
>>>> > I have a rather bizarre intermittent failure that I'd see if anyone else
>>>> > can reproduce.
>>>> >
>>>> > I've taken the following:
>>>> >
>>>> > http://files.squeak.org/5.3/Squeak5.3-19435-64bit/Squeak5.3-19435-64bit-202003021730-Linux.zip
>>>> >
>>>> > Started it up and loaded the latest system updates and the OSProcess
>>>> > package (access OS functions).
>>>> >
>>>> > I then did:
>>>> >
>>>> >     CommandShell command: 'date'
>>>> >
>>>> > This works as I'd expect it too.
>>>> >
>>>> > However, what is interesting is that if I change the time on the machine to
>>>> > any time between 7:36AM and 10:36AM (PDT, I'm in San Jose, CA) for today
>>>> > (May 19th) this call fails with the stack below.  I'm quitting the image
>>>> > between time changes.
>>>> >
>>>> > There was no failure for the same time period yesterday.  Nor does it
>>>> > appear to fail for any other time period today.
>>>> >
>>>> > -- Bob
>>>> >
>>>> > Stack follows:
>>>> >
>>>> > 19 May 2021 10:30:20.503624 am
>>>> >
>>>> > VM: unix - Smalltalk
>>>> > Image: Squeak5.3 [latest update: #19458]
>>>> >
>>>> > SecurityManager state:
>>>> > Restricted: false
>>>> > FileAccess: true
>>>> > SocketAccess: true
>>>> > Working Dir
>>>> > /scratch/bwesterg/squeak/Squeak5.3-19435-64bit-202003021730-Linux/shared
>>>> > Trusted Dir
>>>> > /scratch/bwesterg/squeak/Squeak5.3-19435-64bit-202003021730-Linux/shared/secure
>>>> > Untrusted Dir
>>>> > /scratch/bwesterg/squeak/Squeak5.3-19435-64bit-202003021730-Linux/shared/My
>>>> > Squeak
>>>> >
>>>> > AioEventHandler(Object)>>notify:
>>>> > Receiver: an AioEventHandler
>>>> > Arguments and temporary variables:
>>>> > aString: 'aio event forwarding not supported'
>>>> > Receiver's instance variables:
>>>> > dependents: nil
>>>> > semaphore: nil
>>>> > semaIndex: nil
>>>> > handlerProc: nil
>>>> > descriptor: nil
>>>> >
>>>> > [] in AioEventHandler>>initializeForExceptions:readEvents:writeEvents:
>>>> > Receiver: an AioEventHandler
>>>> > Arguments and temporary variables:
>>>> > <<error during printing>
>>>> > Receiver's instance variables:
>>>> > dependents: nil
>>>> > semaphore: nil
>>>> > semaIndex: nil
>>>> > handlerProc: nil
>>>> > descriptor: nil
>>>> >
>>>> > BlockClosure>>cull:
>>>> > Receiver: [closure] in
>>>> > AioEventHandler>>initializeForExceptions:readEvents:writeEvents:
>>>> > Arguments and temporary variables:
>>>> > firstArg: Warning: aio event forwarding not supported
>>>> > Receiver's instance variables:
>>>> > outerContext:
>>>> > AioEventHandler>>initializeForExceptions:readEvents:writeEvents:
>>>> > startpc: 154
>>>> > numArgs: 1
>>>> >
>>>> > [] in Context>>handleSignal:
>>>> > Receiver: BlockClosure>>on:do:
>>>> > Arguments and temporary variables:
>>>> > <<error during printing>
>>>> > Receiver's instance variables:
>>>> > sender: AioEventHandler>>initializeForExceptions:readEvents:writeEvents:
>>>> > pc: 32
>>>> > stackp: 3
>>>> > method: (BlockClosure>>#on:do: "a CompiledMethod(1660548)")
>>>> > closureOrNil: nil
>>>> > receiver: [closure] in
>>>> > AioEventHandler>>initializeForExceptions:readEvents:writeEvents:...etc...
>>>> >
>>>> > BlockClosure>>ensure:
>>>> > Receiver: [closure] in Context>>handleSignal:
>>>> > Arguments and temporary variables:
>>>> > aBlock: [closure] in Context>>handleSignal:
>>>> > complete: nil
>>>> > returnValue: nil
>>>> > Receiver's instance variables:
>>>> > outerContext: Context>>handleSignal:
>>>> > startpc: 174
>>>> > numArgs: 0
>>>> >
>>>> > Context>>handleSignal:
>>>> > Receiver: BlockClosure>>on:do:
>>>> > Arguments and temporary variables:
>>>> > exception: Warning: aio event forwarding not supported
>>>> > handlerActive: true
>>>> > val: nil
>>>> > Receiver's instance variables:
>>>> > sender: AioEventHandler>>initializeForExceptions:readEvents:writeEvents:
>>>> > pc: 32
>>>> > stackp: 3
>>>> > method: (BlockClosure>>#on:do: "a CompiledMethod(1660548)")
>>>> > closureOrNil: nil
>>>> > receiver: [closure] in
>>>> > AioEventHandler>>initializeForExceptions:readEvents:writeEvents:...etc...
>>>> >
>>>> > Warning(Exception)>>signal
>>>> > Receiver: Warning: aio event forwarding not supported
>>>> > Arguments and temporary variables:
>>>> >
>>>> > Receiver's instance variables:
>>>> > messageText: 'aio event forwarding not supported'
>>>> > tag: nil
>>>> > signalContext: Warning(Exception)>>signal
>>>> > handlerContext: BlockClosure>>on:do:
>>>> > outerContext: nil
>>>> >
>>>> > Warning(Exception)>>signal:
>>>> > Receiver: Warning: aio event forwarding not supported
>>>> > Arguments and temporary variables:
>>>> > signalerText: 'aio event forwarding not supported'
>>>> > Receiver's instance variables:
>>>> > messageText: 'aio event forwarding not supported'
>>>> > tag: nil
>>>> > signalContext: Warning(Exception)>>signal
>>>> > handlerContext: BlockClosure>>on:do:
>>>> > outerContext: nil
>>>> >
>>>> > Warning class>>signal:
>>>> > Receiver: Warning
>>>> > Arguments and temporary variables:
>>>> > signalerText: 'aio event forwarding not supported'
>>>> > Receiver's instance variables:
>>>> > superclass: Notification
>>>> > methodDict: a MethodDictionary(#defaultAction->(Warning>>#defaultAction "a
>>>> > CompiledMethod...etc...
>>>> > format: 65541
>>>> > instanceVariables: nil
>>>> > organization: ('priv handling' defaultAction)
>>>> >
>>>> > subclasses: {Deprecation . ServiceCancelled . SAXWarning .
>>>> > UndeclaredVariableWarning...etc...
>>>> > name: #Warning
>>>> > classPool: nil
>>>> > sharedPools: nil
>>>> > environment: nil
>>>> > category: #'Kernel-Exceptions'
>>>> > suppressed: false
>>>> > resetOnStartUp: false
>>>> >
>>>> > AioEventHandler(Object)>>notify:
>>>> > Receiver: an AioEventHandler
>>>> > Arguments and temporary variables:
>>>> > aString: 'aio event forwarding not supported'
>>>> > Receiver's instance variables:
>>>> > dependents: nil
>>>> > semaphore: nil
>>>> > semaIndex: nil
>>>> > handlerProc: nil
>>>> > descriptor: nil
>>>> >
>>>> > AioEventHandler>>aioEnable:forSemaphore:externalObject:
>>>> > Receiver: an AioEventHandler
>>>> > Arguments and temporary variables:
>>>> > ioDescriptor: nil
>>>> > semaphoreIndex: 17
>>>> > trueOrFalse: true
>>>> > Receiver's instance variables:
>>>> > dependents: nil
>>>> > semaphore: nil
>>>> > semaIndex: nil
>>>> > handlerProc: nil
>>>> > descriptor: nil
>>>> >
>>>> > [] in AioEventHandler>>initializeForExceptions:readEvents:writeEvents:
>>>> > Receiver: an AioEventHandler
>>>> > Arguments and temporary variables:
>>>> > <<error during printing>
>>>> > Receiver's instance variables:
>>>> > dependents: nil
>>>> > semaphore: nil
>>>> > semaIndex: nil
>>>> > handlerProc: nil
>>>> > descriptor: nil
>>>> >
>>>> > BlockClosure>>on:do:
>>>> > Receiver: [closure] in
>>>> > AioEventHandler>>initializeForExceptions:readEvents:writeEvents:
>>>> > Arguments and temporary variables:
>>>> > exceptionOrExceptionSet: Warning
>>>> > handlerAction: [closure] in
>>>> > AioEventHandler>>initializeForExceptions:readEvents:writeEvents:...etc...
>>>> > handlerActive: false
>>>> > Receiver's instance variables:
>>>> > outerContext:
>>>> > AioEventHandler>>initializeForExceptions:readEvents:writeEvents:
>>>> > startpc: 140
>>>> > numArgs: 0
>>>> >
>>>> > AioEventHandler>>initializeForExceptions:readEvents:writeEvents:
>>>> > Receiver: an AioEventHandler
>>>> > Arguments and temporary variables:
>>>> > exceptionEventFlag: true
>>>> > readEventFlag: true
>>>> > writeEventFlag: false
>>>> > Receiver's instance variables:
>>>> > dependents: nil
>>>> > semaphore: nil
>>>> > semaIndex: nil
>>>> > handlerProc: nil
>>>> > descriptor: nil
>>>> >
>>>> > AioEventHandler>>forFileStream:exceptions:readEvents:writeEvents:
>>>> > Receiver: an AioEventHandler
>>>> > Arguments and temporary variables:
>>>> > aFileStream: BufferedAsyncFileReadStream: 'pipeReader'
>>>> > exceptionEventFlag: true
>>>> > readEventFlag: true
>>>> > writeEventFlag: false
>>>> > Receiver's instance variables:
>>>> > dependents: nil
>>>> > semaphore: nil
>>>> > semaIndex: nil
>>>> > handlerProc: nil
>>>> > descriptor: nil
>>>> >
>>>> > AioEventHandler class>>forFileStream:exceptions:readEvents:writeEvents:
>>>> > Receiver: AioEventHandler
>>>> > Arguments and temporary variables:
>>>> > aFileStream: BufferedAsyncFileReadStream: 'pipeReader'
>>>> > exceptionEventFlag: true
>>>> > readEventFlag: true
>>>> > writeEventFlag: false
>>>> > Receiver's instance variables:
>>>> > superclass: Model
>>>> > methodDict: a MethodDictionary(#aioDisable:->(AioEventHandler>>#aioDisable:
>>>> > "a CompiledMethod...etc...
>>>> > format: 65541
>>>> > instanceVariables: #('semaphore' 'semaIndex' 'handlerProc' 'descriptor')
>>>> > organization: ('aio event forwarding' aioDisable:
>>>> > aioEnable:forSemaphore:externalObject:...etc...
>>>> > subclasses: nil
>>>> > name: #AioEventHandler
>>>> > classPool: a Dictionary(#AioPluginPresent->true )
>>>> > sharedPools: nil
>>>> > environment: Smalltalk
>>>> > category: #'OSProcess-AIO'
>>>> >
>>>> > BufferedAsyncFileReadStream(AsyncFileReadStream)>>enableEventHandling
>>>> > Receiver: BufferedAsyncFileReadStream: 'pipeReader'
>>>> > Arguments and temporary variables:
>>>> >
>>>> > Receiver's instance variables:
>>>> >
>>>> >
>>>> > BufferedAsyncFileReadStream(AsyncFileReadStream)>>initialize
>>>> > Receiver: BufferedAsyncFileReadStream: 'pipeReader'
>>>> > Arguments and temporary variables:
>>>> >
>>>> > Receiver's instance variables:
>>>> >
>>>> >
>>>> > BufferedAsyncFileReadStream class(AttachableFileStream
>>>> > class)>>name:attachTo:writable:
>>>> > Receiver: BufferedAsyncFileReadStream
>>>> > Arguments and temporary variables:
>>>> > aSymbolOrString: 'pipeReader'
>>>> > anIOHandle: #[93 179 159 128 0 0 0 0 48 162 123 2 0 0 0 0 0 0 0 0 0 0 0 0]
>>>> > readWriteFlag: false
>>>> > Receiver's instance variables:
>>>> > superclass: AsyncFileReadStream
>>>> > methodDict: a
>>>> > MethodDictionary(#actAsExecutor->(BufferedAsyncFileReadStream>>#a...etc...
>>>> > format: 65552
>>>> > instanceVariables: #('nonBlockingMode' 'readBuffer' 'readSyncSemaphore'
>>>> > 'dataAv...etc...
>>>> > organization: ('finalization' actAsExecutor)
>>>> > ('read ahead buffer' appendAllToBuffer:...etc...
>>>> > subclasses: nil
>>>> > name: #BufferedAsyncFileReadStream
>>>> > classPool: nil
>>>> > sharedPools: nil
>>>> > environment: Smalltalk
>>>> > category: #'OSProcess-Base'
>>>> >
>>>> >
>>>> > --- The full stack ---
>>>> > AioEventHandler(Object)>>notify:
>>>> > [] in AioEventHandler>>initializeForExceptions:readEvents:writeEvents:
>>>> > BlockClosure>>cull:
>>>> > [] in Context>>handleSignal:
>>>> > BlockClosure>>ensure:
>>>> > Context>>handleSignal:
>>>> > Warning(Exception)>>signal
>>>> > Warning(Exception)>>signal:
>>>> > Warning class>>signal:
>>>> > AioEventHandler(Object)>>notify:
>>>> > AioEventHandler>>aioEnable:forSemaphore:externalObject:
>>>> > [] in AioEventHandler>>initializeForExceptions:readEvents:writeEvents:
>>>> > BlockClosure>>on:do:
>>>> > AioEventHandler>>initializeForExceptions:readEvents:writeEvents:
>>>> > AioEventHandler>>forFileStream:exceptions:readEvents:writeEvents:
>>>> > AioEventHandler class>>forFileStream:exceptions:readEvents:writeEvents:
>>>> > BufferedAsyncFileReadStream(AsyncFileReadStream)>>enableEventHandling
>>>> > BufferedAsyncFileReadStream(AsyncFileReadStream)>>initialize
>>>> > BufferedAsyncFileReadStream class(AttachableFileStream
>>>> > class)>>name:attachTo:writable:
>>>> >  - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
>>>> > AttachableFileStream>>asBufferedAsyncFileReadStream
>>>> > ExternalPipe>>setBufferedReader
>>>> > PipeableOSProcess(PipeJunction)>>enableOutputStreamTriggers
>>>> > PipeableOSProcess>>enableEventTriggers
>>>> > PipeableOSProcess(PipeJunction)>>prepareOutputForInternalReader
>>>> > PipeableOSProcess>>prepareOutputForInternalReader
>>>> > PipeableOSProcess(PipeJunction)>>prepareOutputFor:
>>>> > ProxyPipeline>>fromString:shell:
>>>> > ProxyPipeline class>>fromString:shell:
>>>> > CommandShell>>pipelineCollectionFrom:
>>>> > CommandShell>>evaluateOrMakePipelinesFrom:
>>>> > CommandShell>>command:echo:
>>>> > [] in CommandShell>>processCommand:echo:
>>>> > [] in BlockClosure>>newProcess
>>>>