Re: [Pharo-dev] Anyone else seen crashes like these ?

On Mon, 12 Nov 2018 at 21:37, Sven Van Caekenberghe <[hidden email]> wrote:

Hi,

I run Pharo 7 64-bit on a macOS laptop, where the images are kept running across sleep/wake cycles.

Just to confirm, you mean your laptop sleep/wake cycle.

On my Window 10 laptop I do the same quite often with no problems.

 

For many weeks, it often happens that an image crashes before/after such a sleep/wakeup (not all the time, just regularly).

Here is a crash dump from today (fresh image/vm from WE, nothing special loaded).

Related to scheduling ? Event handling ?

In trying to understand the last few moments, is the recent primitives list strongly ordered in time?...

  Most recent primitives

  signal

  nowTick

  primSignal:atUTCMicroseconds:

  wait

  millisecondClockValue

  @

  actualScreenSize

Starting at #actualScreenSize, instrumenting the code by adding...

     Transcript crShow: thisContext sender printString.

indicates the following call chain...

  DisplayScreen-class>>actualScreenSize

  MorphicUIManager>>checkForNewDisplaySize

  DisplayScreen class>>checkForNewScreenSize

  WorldState>>doOneCycleNowFor:

  WorldState>>doOneCycleFor:

  WorldMorph>>doOneCycle

  WorldMorph class>>doOneCycle

  MorphicUIManager>>spawnNewProcess

In detail from a static analysis of the code...

           > WorldState>>doOneCycleNowFor:  

              > DisplayScreen class>>checkForNewScreenSize

                  > MorphicUIManager>>checkForNewDisplaySize 

                      > DisplayScreen-class>>actualScreenSize          PRIMITIVE 

                  < MorphicUIManager>>checkForNewDisplaySize   

               < DisplayScreen class>>checkForNewScreenSize 

            < WorldState>>doOneCycleNowFor

         < WorldState>>doOneCycleFor:  

      < WorldMorph>>doOneCycle  

   < WorldMorph class>>doOneCycle 

< MorphicUIManager>>spawnNewProcess  

   > WorldMorph class>>doOneCycle  

      > WorldMorph>>doOneCycle

         > WorldState>>doOneCycleNowFor:  

            > WorldState>>interCyclePause:

               > Time>>millisecondClockValue       PRIMITIVE

            < WorldState>>interCyclePause:

               > Delay>>schedule

                  > DelaySemaphoreScheduler>>schedule:

                      > Semaphore>>wait                            PRIMITIVE "readyToSchedule variable"

                      > Semaphore>>signal                         PRIMITIVE "timingSemaphore variable"   NOT RECORDED

                                                                                  maybe context change causes this to be recorded later in "Most recent primitives"

                             > DelayMicrosecondTicker>>waitForUserSignalled:orExpired:      waking up from Semaphore>>wait  

                                    the primSignal:atUTCMicroseconds:  PRIMITIVE  immediately before the #wait seems to have been logged now in "Most recent primitives"

                             > DelaySemaphoreScheduler>>scheduleAtTimingPriority

                                > Semaphore>>signal               PRIMITIVE  "readyToSchedule variable"  seems to have not been recorded in "Most recent primitives"

                                > DelayBasicScheduler>>scheduleAtTimingPriority

                             < DelaySemaphoreScheduler>>scheduleAtTimingPriority

                          < DelayBasicScheduler>>runBackendLoopAtTimingPriority

                             > DelayMicrosecondTicker>>nowTick         PRIMITIVE 

                             > Delay>>timingPrioritySignalExpired         

                                > Semaphore>>signal                PRIMITIVE "delaySemaphore variable"      CRASH

 Smalltalk stack dump:

    0x7ffee21d7138 M Delay>timingPrioritySignalExpired 0x113e3b138: a(n) Delay

    0x7ffee21d7170 M [] in DelaySemaphoreScheduler(DelayBasicScheduler)>runBackendLoopAtTimingPriority 0x11453b8c0: a(n) DelaySemaphoreScheduler

       0x1169f51c8 s BlockClosure>ensure:

       0x1169f5828 s DelaySemaphoreScheduler(DelayBasicScheduler)>runBackendLoopAtTimingPriority

       0x1169f5c38 s [] in DelaySemaphoreScheduler(DelayBasicScheduler)>startTimerEventLoopPriority:

       0x1169fae10 s [] in BlockClosure>newProcess

The only reason I can think that last semaphore call would be a problem is if variable delaySemaphore was not a Semaphore,

but the C stack backtrace doesn't look like it crashes in the Semaphore handling.

Its perhaps co-incidental with delay scheduling code is invoked fairly often, that its the current process when this crash occurs.

To hep isolate the failure point, I would considering copying #nowTIck to a multiple series like...

#nowTick1

#nowTick2

#nowTick3

etc so that all of the sender sites can be made distinct.

And maybe the same for #signal senders within the delay scheduling code.

One side-curiousity is I can't see where the primitive #@ is being called from.

Does it indicate some loop as its trying to determine 

To me the "vmIOProcessEvents" in the C backtrace with a fairly deep stack into the AppKit framework 

indicates its related to event handling.

cheers -ben