[10.14 Mojave] Immer wieder Einfrieren für einige Sekunden

[Ijon Tichy]

Das Phänomen ist inzwischen vereinzelt wieder aufgetreten. Allerdings nur bei schlechter WLAN-Verbindung. Dennoch seltsam, das dann auch die Uhr stehen bleibt - was könnte das mit der WLAN-Verbindung zu tun haben?

 

[dg2rbf]

Hi,
scheinbar zieht die Zeitsynchronisierung mit dem NTP-Server bei schlechter W-Lan Verbindung das System runter.
franz

 

[Ijon Tichy]

Das Phänomen Zeit tritt nun doch weiterhin auf, leider auch bei guter WLAN-Verbindung.

Irgendwelche neuen Ideen?

 

[Ijon Tichy]

So, jetzt habe ich endlich mal das Einfrieren gehabt während die Konsole offen war. Folgendes stand dort im Moment des Einfrierens:

standard    17:10:52.056757 +0200    kernel    X86PlatformPlugin fSMC_PLimitNotification
standard    17:10:52.056764 +0200    kernel    X86PlatformPlugin fSMC_PLimitNotification
standard    17:10:52.056771 +0200    kernel    X86PlatformPlugin::evaluateSoftLimit calling cgDispatchCallback
standard    17:10:52.056773 +0200    kernel    X86PlatformPlugin::evaluateSoftLimit calling cgDispatchCallback
standard    17:10:52.056916 +0200    kernel    X86PlatformPlugin::evaluateSoftLimit NOT calling cgDispatchCallback
standard    17:10:52.056918 +0200    kernel    X86PlatformPlugin::evaluateSoftLimit NOT calling cgDispatchCallback
standard    17:10:52.056922 +0200    kernel    X86PlatformPlugin::evaluateSoftLimit NOT calling cgDispatchCallback
standard    17:10:52.056924 +0200    kernel    X86PlatformPlugin::evaluateSoftLimit NOT calling cgDispatchCallback
standard    17:10:52.056927 +0200    kernel    X86PlatformPlugin::evaluateSoftLimit NOT calling cgDispatchCallback
standard    17:10:52.056929 +0200    kernel    X86PlatformPlugin::evaluateSoftLimit NOT calling cgDispatchCallback
standard    17:10:52.056932 +0200    kernel    X86PlatformPlugin::evaluateSoftLimit NOT calling cgDispatchCallback
standard    17:10:52.056934 +0200    kernel    X86PlatformPlugin::evaluateSoftLimit NOT calling cgDispatchCallback
standard    17:10:52.056937 +0200    kernel    X86PlatformPlugin result 0
standard    17:10:52.056939 +0200    kernel    X86PlatformPlugin result 0

Nachdem es weiterging, kamen Einträge von der Mail-App:

standard    17:10:52.108386 +0200    Mail    [MeineMailbox - Eingang] <Sync> Sync UIDs operation finished; fetched message numbers (6051): 24542:30592; fetched UIDs (6051); new UIDs (0): (null); existing UIDs (6051); UIDs with flag changes (0): (null); expunged persistent IDs (0): <NSMutableIndexSet: 0x6000067ff1e0>(no indexes), 0 flag changes to persist
standard    17:10:52.108495 +0200    Mail    [MeineMailbox - Eingang] <Sync> Operation {<IMAPSyncUIDsFlagsAndLabelsOperation: 0x6000082852d0> message numbers: 24542:30592} finished
standard    17:10:52.108568 +0200    Mail    [MeineMailbox - Eingang] <Sync> Recalculated priorities - network: 24, persistence: 0
standard    17:10:52.109348 +0200    Mail    [MeineMailbox] Assigning active tasks with selected mailboxes: Eingang, Entwürfe, Ap<16 chars><B8C5>
standard    17:10:52.109728 +0200    Mail    [MeineMailbox] Performing next operation for [<IMAPMailboxSyncTask: 0x7fe0a34bcef0> mailboxName: Eingang; priorities - network: 24, reserved network: 0, persistence: 0] on handler: <IMAPNetworkTaskHandler: 0x60000063a080> currentMailboxName=Eingang
standard    17:10:52.110003 +0200    Mail    [MeineMailbox - Eingang] <Sync> Operation {<IMAPSyncUIDsFlagsAndLabelsOperation: 0x600000255880> message numbers: 19405:24541} created
standard    17:10:52.110450 +0200    Mail    [imap.1und1.de] <0x7fe0aaaf3de0:[Selected mailbox=Eingang - MeineMailbox]> Wrote: 1015.105 FETCH 19405:24541 (FLAGS UID)
standard    17:10:52.198004 +0200    Mail    [imap.1und1.de] <0x7fe0aaaf3de0:[Selected mailbox=Eingang - MeineMailbox]> Read: * FETCH 19405(UID 202811 FLAGS (\Seen))
standard    17:10:52.198183 +0200    Mail    [imap.1und1.de] <0x7fe0aaaf3de0:[Selected mailbox=Eingang - MeineMailbox]> Read: * FETCH 19406(UID 202812 FLAGS (\Seen))
standard    17:10:52.198328 +0200    Mail    [imap.1und1.de] <0x7fe0aaaf3de0:[Selected mailbox=Eingang - MeineMailbox]> Read: * FETCH 19407(UID 202813 FLAGS (\Seen))
standard    17:10:52.198506 +0200    Mail    [imap.1und1.de] <0x7fe0aaaf3de0:[Selected mailbox=Eingang - MeineMailbox]> Read: * FETCH 19408(UID 202814 FLAGS (\Seen))
standard    17:10:52.198641 +0200    Mail    [imap.1und1.de] <0x7fe0aaaf3de0:[Selected mailbox=Eingang - MeineMailbox]> Read: * FETCH 19409(UID 202815 FLAGS (\Seen))
[... mehr davon ...]
standard    17:10:52.336716 +0200    wirelessproxd    WPDClient - Device Discovered: Client (76A2EBBA-0F32-46BA-9274-7BC1FB560FFF) Process (sharingd) Device (5C69B904-B8EA-4815-BFF1-11E4A5E15215) Type (16) Data (<4c001006 331edf13 62ff>)
standard    17:10:52.336784 +0200    wirelessproxd    Telling process sharingd about discovered device 5C69B904-B8EA-4815-BFF1-11E4A5E15215 of type 16 with data <4c001006 331edf13 62ff>
standard    17:10:52.346970 +0200    sharingd    Nearby didDiscoverType 1 UUID 5C69B904-B8EA-4815-BFF1-11E4A5E15215 info {
    WPNearbyKeyDeviceAddress = <9860cad0 0924>;
    WPNearbyKeyManufacturerData = <4c001006 331edf13 62ff>;
    WPNearbyKeyPaired = 0;
    WPNearbyKeyRSSI = 80;
    kDeviceChannel = 37;
}
[.... noch mehr mailbox sync ...]

Was das mit dem X86PlatformPlugin sein könnte, ist mir ein Rätsel, aber das scheint mir auch nicht das Problem zu sein. Ich vermute eher, dass die Mail-App mal kurz alles blockiert, wenn sie mit dem IMAP-Konto synchronisiert. Ich habe ziemlich viele Mails auf dem Server (über 30.000). Was aber dagegen spricht, ist, dass ein manuell angestoßener Mail-Empfang zu keinem Blockieren führt.

Stutzig macht mich auch ein bisschen der zwischendrin erscheinende Eintrag mit dem entdeckten WiFi-Device. Was ist das denn, und kann das eine Ursache sein?

Erst mal bin ich jetzt nicht wirklich viel schlauer....


NACHTRAG:

Gerade eben wieder kurzes Einfrieren mit folgenden als Problem gekennzeichneten Log-Einträgen in der Komsole:

standard    17:31:50.007443 +0200    com.apple.WebKit.WebContent    Current memory footprint: 14 MB
problem    17:31:50.690412 +0200    kernel    virtual IOReturn IOAccelEventMachine2::waitForStamp(int32_t, stamp_t, stamp_t *): timeout waiting for IntelAccelerator stamp 5621884 (gpu_stamp=5621883)
problem    17:31:50.690417 +0200    kernel    void IOAccelEventMachine2::handleFinishChannelRestart(IOReturn, int32_t, uint32_t) - Setting restart type to 4
problem    17:31:50.690419 +0200    kernel    void IOAccelEventMachine2::handleFinishChannelRestart(IOReturn, int32_t, uint32_t): GPURestartDequeued stampIdx=4 type=4 fromWhere=1 waitingOnIdx=4
standard    17:31:50.690421 +0200    kernel    [IGPU] display event timeout on index = 4
problem    17:31:50.690464 +0200    kernel    void IOAccelEventMachine2::restart_channel(): GPURestartSkipped stampIdx=4 type=4
problem    17:31:50.690466 +0200    kernel    void IOAccelEventMachine2::restart_channel(): no channel associated with stamp_idx 4 (type 4)
standard    17:31:50.703028 +0200    com.apple.WebKit.WebContent    0x7fc4fb203f20 - WebProcess::destroyRenderingResources() took 4201.96ms

Das ist ja nun anscheinend wieder ganz was anderes – ohne dass ich eine Ahnung hätte, was es genau ist. Ich werde immer ratloser...

 

[ottomane]

WebProcess::destroyRenderingResources() took 4201.96ms

timeout waiting for IntelAccelerator stamp 5621884 (gpu_stamp=5621883)

GPURestartDequeued

Das klingt nicht nach gesunder Hardware (GPU). Marcel hatte weiter oben schon einen treffenden Hinweis gegeben.

 

[Wuchtbrumme]

daran erinnere ich mich auch. Wie hast Du denn die Konsole offengehabt? Mit oder ohne Filter nach "problem" oder "error"? Weil die läuft so schnell durch, bis das anhält zeigt es längst was anderes an. Nur mit Filter macht halbwegs Sinn.

 

[Ijon Tichy]

Die Konsole war ohne Filter offen. Danke für den Hinweis. Allerdings blieb die Konsole ja auch stehen, sodass ich die letzte Meldung lesen konnte.

GPU halte ich für unwahrscheinlich, da ich keine Grafikprobleme habe und Videos problemlos laufen. Oder irre ich mich da?

 

[Ijon Tichy]

Das klingt nicht nach gesunder Hardware (GPU). Marcel hatte weiter oben schon einen treffenden Hinweis gegeben.

Der Aufräumprozess scheint aber vom Browser zu sein, oder? Vielleicht zu viele Tabs offen? Ich hatte schon ein paar mal das Gefühl, dass Safari hier ein Problem hat, kann es aber nicht genauer beschreiben.

 

[Wuchtbrumme]

Die Konsole war ohne Filter offen. Danke für den Hinweis. Allerdings blieb die Konsole ja auch stehen, sodass ich die letzte Meldung lesen konnte.

Du hast meinen Post gelesen?

Weil die läuft so schnell durch, bis das anhält zeigt es längst was anderes an. Nur mit Filter macht halbwegs Sinn.

 

[ottomane]

Der Aufräumprozess scheint aber vom Browser zu sein, oder?

Ja.

Vielleicht zu viele Tabs offen?

Hm, ich habe immer zig (50?) Tabs offen. Allerdings inzwischen unter Big Sur.

Mein Orakel sagt weiter GPU. Es wurde versucht, sie neuzustarten (schon nicht normal, IMO) und dann wurde es aufgegeben (timeout, skipped). Der Browser musste 4,2 Sekunden warten -> das Hakeln. Weil das weit unten im System ist, stockt das ganze Display.

Aber ich kann gut falsch liegen. Vielleicht mag sich @Marcel Bresink dazu noch mal äußern.

 

[Wuchtbrumme]

#4

 

[Ijon Tichy]

Wie kann ich denn die GPU testen? Ich habe im Internet was von "Heaven" gefunden und das mal laufen lassen. Keine Probleme. Ich schau auch manchmal Filme auf Netflix und habe da nie Probleme. Müsste sich ein GPU-Problem da nicht auch bemerkbar machen?

 

[Ijon Tichy]

Nun finde ich bei jedem Einfrieren folgenden Meldungen im Log:

fehler    16:09:43.619241 +0200    kernel    compat_ifmu_ulist: en0 copyin() error 14
fehler    16:09:43.619261 +0200    kernel    compat_ifmu_ulist: en1 copyin() error 14
fehler    16:09:43.619271 +0200    kernel    compat_ifmu_ulist: en2 copyin() error 14
fehler    16:09:43.619279 +0200    kernel    compat_ifmu_ulist: p2p0 copyin() error 14
fehler    16:09:43.619285 +0200    kernel    compat_ifmu_ulist: awdl0 copyin() error 14
fehler    16:09:43.619749 +0200    kernel    compat_ifmu_ulist: en0 copyin() error 14
fehler    16:09:43.619767 +0200    kernel    compat_ifmu_ulist: en1 copyin() error 14
fehler    16:09:43.619778 +0200    kernel    compat_ifmu_ulist: en2 copyin() error 14
fehler    16:09:43.619983 +0200    kernel    compat_ifmu_ulist: p2p0 copyin() error 14
fehler    16:09:43.619996 +0200    kernel    compat_ifmu_ulist: awdl0 copyin() error 14
problem    16:09:49.019859 +0200    kernel    virtual IOReturn IOAccelEventMachine2::waitForStamp(int32_t, stamp_t, stamp_t *): initial wait for 1 second expired. Continue wait for 4 seconds. stamp 6298515 (gpu_stamp=6298514)
fehler    16:09:50.284606 +0200    hidd    <private>: Event enqueue error:0xe00002e8 type:11 sender:0x10003d8f2
fehler    16:09:50.291386 +0200    hidd    <private>: Event enqueue dropped:1 consecutive events
fehler    16:09:50.291447 +0200    hidd    <private>: Event enqueue error:0xe00002e8 type:11 sender:0x10003d8f2
fehler    16:09:50.959841 +0200    com.apple.WebKit.Networking    TIC Read Status [77359:0x7f816d077eb0]: 1:57
fehler    16:09:50.959933 +0200    com.apple.WebKit.Networking    TIC Read Status [77359:0x7f816d077eb0]: 1:57
fehler    16:09:50.959957 +0200    com.apple.WebKit.Networking    TIC Read Status [77359:0x7f816d077eb0]: 1:57
fehler    16:09:50.963722 +0200    com.apple.WebKit.Networking    nw_protocol_boringssl_get_output_frames(1301) <private>[0x7f8168493f00] get output frames failed, state 8196
fehler    16:09:50.963763 +0200    com.apple.WebKit.Networking    nw_protocol_boringssl_get_output_frames(1301) <private>[0x7f8168493f00] get output frames failed, state 8196
fehler    16:09:50.964180 +0200    com.apple.WebKit.Networking    TIC Read Status [77359:0x0]: 1:57
fehler    16:09:50.964197 +0200    com.apple.WebKit.Networking    TIC Read Status [77359:0x0]: 1:57
fehler    16:09:50.964211 +0200    com.apple.WebKit.Networking    TIC Read Status [77359:0x0]: 1:57
fehler    16:09:50.964227 +0200    com.apple.WebKit.Networking    TIC Read Status [77359:0x0]: 1:57
fehler    16:09:51.369515 +0200    mds_stores    si_remotepsid_gettmpath:724: Got reply <xpc object>
problem    16:09:53.020153 +0200    kernel    virtual IOReturn IOAccelEventMachine2::waitForStamp(int32_t, stamp_t, stamp_t *): timeout waiting for IntelAccelerator stamp 6298515 (gpu_stamp=6298514)
problem    16:09:53.020167 +0200    kernel    void IOAccelEventMachine2::handleFinishChannelRestart(IOReturn, int32_t, uint32_t) - Setting restart type to 4
problem    16:09:53.020171 +0200    kernel    void IOAccelEventMachine2::handleFinishChannelRestart(IOReturn, int32_t, uint32_t): GPURestartDequeued stampIdx=4 type=4 fromWhere=1 waitingOnIdx=4
problem    16:09:53.020219 +0200    kernel    void IOAccelEventMachine2::restart_channel(): GPURestartSkipped stampIdx=4 type=4
problem    16:09:53.020221 +0200    kernel    void IOAccelEventMachine2::restart_channel(): no channel associated with stamp_idx 4 (type 4)

In der Apple Community und auf Reddit habe ich Leidensgenossen, aber leider keine Lösung dazu gefunden.

Im Apple-Thread sagen einige, dass es mit Safari zusammenzuhängen scheint (das scheint mir ja auch so) und dass ein Neustart für 1-2 Wochen zu helfen scheint. Das probiere ich jetzt mal.

 

[ottomane]

Eine Anwendung allein sollte -- ein korrekt funktionierendes Betriebssystem, Treiber und Hardware vorausgesetzt, nicht das ganze System einfrieren lassen können.

Ansonsten stehen hier j wieder die gleichen Fehler wie zuvor.

problem 16:09:53.020219 +0200 kernel void IOAccelEventMachine2::restart_channel(): GPURestartSkipped stampIdx=4 type=4

 

[Ijon Tichy]

Eine Anwendung allein sollte -- ein korrekt funktionierendes Betriebssystem, Treiber und Hardware vorausgesetzt, nicht das ganze System einfrieren lassen können.

Da hast du sicher recht.

Manche vermuten ein Problem in macOS Mojave, evtl. schon seit High Sierra und auch noch in Catalina. Offensichtlich tritt es auch auf frisch installierten Systemen auf. Es gibt einige Berichte von Usern, die auf Sierra zurückgegangen sind und seitdem keine Probleme mehr haben.

Allerdings kann ich mich nicht erinnern, das Problem früher schon gehabt zu haben.

 

[Ijon Tichy]

Zwischeninfo:

Seit dem letzten Safari-Update ist das Problem jetzt nicht mehr aufgetreten! Ich wage kaum zu hoffen, aber vielleicht…?

 

[Ijon Tichy]

Neues Update und vorläufiges Fazit:

Auch nach dem Safari-Update trat das Problem wieder auf. Bis jetzt allerdings nicht so gehäuft.

Es sieht so aus, als ob ein Neustart das Problem tatsächlich für etwa 1-2 Wochen behebt. Dann beginnt es, gelegentlich wieder aufzutreten, wobei die Häufigkeit langsam ansteigt. Verursacht wird das Problem oft, aber nicht ausschließlich, von Safari, wenn komplexe Seiten angezeigt werden – z.B. Seiten, die viel mit Javascript Nachladen.

Meine Vermutung ist, dass der Grafiktreiber einen Bug hat, der nur unter bestimmten Umständen zum Tragen kommt, und dass dieser Bug gelegentlich vor allem durch Safari getriggert wird.

Ich bereite gerade einen OS-Update auf Big Sur vor. Bin gespannt ob das Phänomen dann weg ist.