Welcome to our new forum
All users of the legacy CODESYS Forums, please create a new account at account.codesys.com. But make sure to use the same E-Mail address as in the old Forum. Then your posts will be matched. Close

PFC200 hängt sich auf

jago85
2019-09-16
2019-09-26
  • jago85 - 2019-09-16

    Hallo,

    wir stellten vor kurzem fest, dass sich unsere PFC200 (FW13) mit CODESYS for PFC200 SL (3.5.15.0) wiederholt aufhängt. Dabei stürzt die Steuerung komplett ab. Sie reagiert weder auf Ping noch auf Eingaben über RS232 (RS232 ist der Linux-Shell zugeordnet). Eine der LEDs, die eigentlich im selbstständig blinken soll, bleibt statisch an oder aus.

    Aktuell tappen wir leider noch im Dunkeln, was die Ursache dafür ist. Nach aktuellem Kenntnisstand treten die Abstürze nur auf, wenn unsere CODESYS-Applikation läuft. Eine zweite Steuerung haben wir bereits getestet. Diese zeigt das Verhalten auch. Beide haben auch eine aktivierte Lizenz.

    Möglicherweise hängt das Problem mit der Aktivierung/Deaktivierung des CAN-Bus und der CANopen-Knoten zusammen. Unser System wacht zyklisch auf, ruft einige Daten ab und schaltet dann wieder ab. Beim Aufruf des Reconfigure-FB scheint eine hohe Last aufzutreten. Obwohl wir den Aufruf in einen eigenen Task mit niedrigerer Priorität ausgelagert haben, wird auch der Haupttask dabei verzögert > 150 ms bei normalerweise 25 ms Zykluszeit.

    Über das Wochenende lief unsere Steuerung ohne Aktivierung/Deaktivierung des CAN-Bus durch. Danach habe ich heute Morgen das Verhalten wieder aktiviert und dabei alle 30 Sekunden den CAN-Bus und sämtliche Knoten aktiviert und nach dem Aktualisieren aller Daten wieder deaktiviert. Die Steuerung hängt sich meistens innerhalb von 30 Minuten bis 3 Stunden auf.

    Bei 3S hat man sich ja sicher auch intensiv mit der Steuerung befasst. Gibt es hier vielleicht irgendwelche Tipps, wie man das Problem lokalisieren kann?

    Bekommt man heraus, ob ein Kernel-Panic-Ereignis aufgetreten ist?

    Ist es überhaupt möglich, mit einer CODESYS-User-Applikation einen derartigen Fehler zu programmieren, dass das System komplett einfriert?

    Oder könnte hier ein Fehler in einem Treiber, der nicht mit dem öfteren Aktivieren/Deaktivieren zurecht kommt, das Problem hervorrufen?

    VG,
    Jan

     
  • eschwellinger

    eschwellinger - 2019-09-17

    Hi,

    ich würde wie folgt vorgehen:

    per ssh auf dem PFC einloggen ( zum Beispiel mit putty oder irgend einem ssh client)
    dann die SPS stoppen mit:

    /etc/init.d/codesyscontrol stop

    dann die Runtime manuell starten mit:
    cd /var/opt/codesys/opt/codesys/bin/codesyscontrol.bin -d /etc/CODESYSControl.cfg

    dann mal so laufen lassen also Putty nicht beenden... dann solltest du sehen wenn der Absturz passiert und was da genau im Argen ist.

    Grüße
    Edwin

     
  • jago85 - 2019-09-25

    Hi Edwin,

    danke erstmal für die Antwort.

    Ich habe damit bereits einige Tests gemacht. Um den Zeitpunkt des Absturzes besser zu sehen, habe ich noch jede Zeile mit einem Timestamp erweitert.
    (Falls das für jemanden nützlich ist, hier der Befehl:)
    /opt/codesys/bin/codesyscontrol.bin -d /etc/CODESYSControl.cfg | awk '{ print strftime("[%Y-%m-%d %H:%M:%S]"), $0 }'

    Die Ausgaben von CODESYS sind bisher zumindest für mich wenig aufschlussreich. Bei jedem Aufstarten des CAN-Bus kommen einige Ausgaben und irgendwo ist dann plötzlich Schluss. An dem Punkt ist soweit nichts Auffälliges.

    (Schade, dass das Forum hier keine Spoiler unterstützt um solche langen Code-Sektionen einzuklappen, oder habe ich das übersehen?)

    Ende des Logs mit Nutzung von FB Reconfigure

    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4063,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4064,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4065,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4066,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4067,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4068,OSprio:0) running
    [2019-09-19 03:42:07] log_event_logid[1111]: log_EVENT_LogId(0x50103, 1)
    [2019-09-19 03:42:07] log_event_logid[1111]: log_EVENT_LogId(0x50110, 1)
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4069,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4070,OSprio:0) running
    [2019-09-19 03:42:07] onError[261]: controller problem 0x0 on can0
    [2019-09-19 03:42:07] onError[295]: protocol violation type 0x0 location 0x19 on can0
    [2019-09-19 03:42:07] onError[261]: controller problem 0x20 on can0
    [2019-09-19 03:42:07] onError[280]: [TX passive]
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4071,OSprio:0) running
    [2019-09-19 03:42:07] onError[261]: controller problem 0x20 on can0
    [2019-09-19 03:42:07] onError[280]: [TX passive]
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4072,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4073,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4074,OSprio:0) running
    [2019-09-19 03:42:07] log_event_logid[1111]: log_EVENT_LogId(0x50101, 1)
    [2019-09-19 03:42:07] log_event_logid[1111]: log_EVENT_LogId(0x50110, 1)
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4075,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4076,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4077,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4078,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4079,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4080,OSprio:0) running
    [2019-09-19 03:42:07] log_event_logid[1111]: log_EVENT_LogId(0x50103, 1)
    [2019-09-19 03:42:07] log_event_logid[1111]: log_EVENT_LogId(0x50110, 1)
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4082,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4083,OSprio:0) running
    [2019-09-19 03:42:07] onError[261]: controller problem 0x0 on can0
    [2019-09-19 03:42:07] onError[261]: controller problem 0x20 on can0
    [2019-09-19 03:42:07] onError[280]: [TX passive]
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4084,OSprio:0) running
    [2019-09-19 03:42:07] onError[234]: bus off on can0
    [2019-09-19 03:42:07] RxThread[428]: read(can0):Network is down
    [2019-09-19 03:42:07] CMD_ResetAlarm[922]: ifconfig can0 down
    [2019-09-19 03:42:07] CMD_ResetAlarm[926]: ifconfig can0 up
    [2019-09-19 03:42:07] CMD_Send[862]: write can0: Network is down
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4089,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:07] SysTaskFrame[444]:  AsyncTask128(tid:4090,OSprio:0) running
    [2019-09-19 03:42:07] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4091,OSprio:0) running
    [2019-09-19 03:42:39] log_event_logid[1111]: log_EVENT_LogId(0x50101, 1)
    [2019-09-19 03:42:39] log_event_logid[1111]: log_EVENT_LogId(0x50110, 1)
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4092,OSprio:0) running
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4093,OSprio:0) running
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4094,OSprio:0) running
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4095,OSprio:0) running
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4096,OSprio:0) running
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4097,OSprio:0) running
    [2019-09-19 03:42:39] log_event_logid[1111]: log_EVENT_LogId(0x50103, 1)
    [2019-09-19 03:42:39] log_event_logid[1111]: log_EVENT_LogId(0x50110, 1)
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4098,OSprio:0) running
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4099,OSprio:0) running
    [2019-09-19 03:42:39] onError[261]: controller problem 0x0 on can0
    [2019-09-19 03:42:39] onError[261]: controller problem 0x20 on can0
    [2019-09-19 03:42:39] onError[280]: [TX passive]
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4100,OSprio:0) running
    [2019-09-19 03:42:39] onError[234]: bus off on can0
    [2019-09-19 03:42:39] RxThread[428]: read(can0):Network is down
    [2019-09-19 03:42:39] CMD_ResetAlarm[922]: ifconfig can0 down
    [2019-09-19 03:42:39] CMD_ResetAlarm[926]: ifconfig can0 up
    [2019-09-19 03:42:39] CMD_Send[862]: write can0: Network is down
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4104,OSprio:0) running
    [2019-09-19 03:42:39] onError[295]: protocol violation type 0x4 location 0x0 on can0
    [2019-09-19 03:42:39] onError[309]: [bit stuffing error]
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4105,OSprio:0) running
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4106,OSprio:0) running
    [2019-09-19 03:42:39] log_event_logid[1111]: log_EVENT_LogId(0x50101, 1)
    [2019-09-19 03:42:39] log_event_logid[1111]: log_EVENT_LogId(0x50110, 1)
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4107,OSprio:0) running
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4108,OSprio:0) running
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4109,OSprio:0) running
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4110,OSprio:0) running
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4111,OSprio:0) running
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4112,OSprio:0) running
    [2019-09-19 03:42:39] log_event_logid[1111]: log_EVENT_LogId(0x50103, 1)
    [2019-09-19 03:42:39] log_event_logid[1111]: log_EVENT_LogId(0x50110, 1)
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4113,OSprio:0) running
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4114,OSprio:0) running
    [2019-09-19 03:42:39] onError[261]: controller problem 0x0 on can0
    [2019-09-19 03:42:39] onError[295]: protocol violation type 0x4 location 0x0 on can0
    [2019-09-19 03:42:39] onError[309]: [bit stuffing error]
    [2019-09-19 03:42:39] onError[261]: controller problem 0x20 on can0
    [2019-09-19 03:42:39] onError[280]: [TX passive]
    [2019-09-19 03:42:39] SysTaskCreate[516]: create AsyncTask128(prio:128,interval:0us,stacksize:131072)
    [2019-09-19 03:42:39] SysTaskFrame[444]:  AsyncTask128(tid:4115,OSprio:0) running
    [2019-09-19 03:42:39] onError[234]: bus off on can0
    [2019-09-19 03:42:39] RxThread[428]: read(can0):Network is down
    

    Ohne Reconfigure kommen viele Meldungen, vermutlich weil keine CAN-Messages mehr gesendet werden können:

    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] log_event_logid[1111]: log_EVENT_LogId(0x50110, 1)
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:02] onError[234]: bus off on can0
    [2019-09-19 18:03:02] RxThread[428]: read(can0):Network is down
    [2019-09-19 18:03:02] CMD_ResetAlarm[922]: ifconfig can0 down
    [2019-09-19 18:03:02] CMD_ResetAlarm[926]: ifconfig can0 up
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: Network is down
    [2019-09-19 18:03:02] onError[261]: controller problem 0x8 on can0
    [2019-09-19 18:03:02] onError[290]: [TX warning]
    [2019-09-19 18:03:02] onError[261]: controller problem 0x20 on can0
    [2019-09-19 18:03:02] onError[280]: [TX passive]
    [2019-09-19 18:03:02] log_event_logid[1111]: log_EVENT_LogId(0x50101, 1)
    [2019-09-19 18:03:02] log_event_logid[1111]: log_EVENT_LogId(0x50110, 1)
    [2019-09-19 18:03:02] log_event_logid[1111]: log_EVENT_LogId(0x50103, 1)
    [2019-09-19 18:03:02] onError[261]: controller problem 0x0 on can0
    [2019-09-19 18:03:02] onError[261]: controller problem 0x20 on can0
    [2019-09-19 18:03:02] onError[280]: [TX passive]
    [2019-09-19 18:03:02] CMD_Send[862]: write can0: No buffer space available
    [20 Wiederholungen]
    [2019-09-19 18:03:03] CMD_Send[862]: write can0: No buffer space available
    [76 Wiederholungen]
    [2019-09-19 18:03:04] CMD_Send[862]: write can0: No buffer space available
    [76 Wiederholungen]
    [2019-09-19 18:03:05] CMD_Send[862]: write can0: No buffer space available
    [76 Wiederholungen]
    [2019-09-19 18:03:05] CMD_Send[862]: write can0: No buffer space available
    [77 Wiederholungen]
    [2019-09-19 18:03:07] CMD_Send[862]: write can0: No buffer space available
    [76 Wiederholungen]
    [2019-09-19 18:03:08] CMD_Send[862]: write can0: No buffer space available
    [76 Wiederholungen]
    [2019-09-19 18:03:09] CMD_Send[862]: write can0: No buffer space available
    [77 Wiederholungen]
    [2019-09-19 18:03:10] CMD_Send[862]: write can0: No buffer space available
    [76 Wiederholungen]
    [2019-09-19 18:03:11] CMD_Send[862]: write can0: No buffer space available
    [55 Wiederholungen]
    [2019-09-19 18:03:11] log_event_logid[1111]: log_EVENT_LogId(0x50110, 1)
    [2019-09-19 18:03:11] CMD_Send[862]: write can0: No buffer space available
    [17 Wiederholungen]
    [2019-09-19 18:03:11] CMD_Send[862]: write can0: No buffer space available
    [2019-09-19 18:03:11] onError[234]: bus off on can0
    [2019-09-19 18:03:11] RxThread[428]: read(can0):Network is down
    

    So eine richtig heiße Spur hat sich noch nicht ergeben. Bei jedem Aufstarten des CAN-Bus durchläuft unsere Steuerung eine Statemachine. Zuerst wird der CAN-Bus aktiviert, dann wird ResetBusAlarm() ausgeführt. Danach werden die CANopen-Knoten nacheinander aktiviert und deren Spannungsversorgung zugeschaltet. Nach dem Abschalten des Bus wird nochmals ResetBusAlarm() ausgeführt.

    Zunächst sah es so aus, als würde es besser laufen, wenn ResetBusAlarm() nicht ausgeführt wird. Das System lief einige Stunden. Über Nacht passierte dann letztendlich doch wieder ein Absturz. Als nächstes habe ich die Reconfigure-FBs ganz aus dem Ablauf herausgenommen. Und auch hier stürzte das System ab. Das nächste Mal lief es mehrere Tage durch, ohne etwas geändert zu haben.

    Nun habe ich ein Trace die ganze Zeit mitlaufen lassen und so wie es aussieht, stürzt die Steuerung kurz nach dem Einschalten des CAN-Bus ab. Der DEVICE_STATE des zuerst zugeschalteten Knotens ist beim Absturz UNKNOWN oder NOT_AVAIL. Danach kommt sonst PRE_OPERATIONAL, wenn es normal weiter laufen würde.

    Beim Einschalten des ersten CAN-Knotens kommt es im Trace zu einer kleinen Lücke. Auch ResetBusAlarm() ruft solch eine Lücke hervor. Und das, obwohl ResetBusAlarm() extra in einem eigenen Task mit niedrigerer Priorität aufgerufen wird. Ist hier vielleicht ein Treiber verantwortlich, der mit hoher Priorität alles andere verzögert?

    Bei meinen neuesten Untersuchungen kam eine Tendenz zum Vorschein, dass die Lücke im Trace kleiner 200 ms ist, wenn das System nicht abstürzt. Bei einer Aufzeichnung, welche ich vor einem Absturz aufgenommen habe, waren die Lücken alle über 240 ms, manchmal fast 400 ms. Evtl. bringt so eine Verzögerung auch die Kommunikation mit dem KBus durcheinander (?).
    Hier läuft es noch:

    Hier stürzt es ab: (Allerdings findet der Absturz nicht jedes mal direkt nach der sehr langen Lücke statt.)

    Zuletzt habe ich noch beobachtet, dass die Lücke beim Starten des ersten CAN-Gerätes nicht auftritt, ein PCAN-Adapter an Bus hängt (Listen Only ist deaktiviert => PCAN schickt Acknowledges für jede CAN-Nachricht).

    Kann es sein, dass der CAN-Treiber für die Laufzeitverzögerungen verantwortlich ist?

    Wie verhalten sich eigentlich die Ausgangs-Scheiben, bei einem System-Crash?
    Gehen die aus oder behalten die ihren letzten Zustand bei? Soweit ich gesehen habe, war unser CANopen-Gerät nach dem Crash aus. Stellt sich die Frage, ob es vielleicht gar nicht eingeschaltet wurde oder ob der Ausgang, der die Spannung schaltet nach den Crash ausgeht, weil der KBus nicht mehr aktualisiert wird.

    Hier nochmal die Frage:
    Ist es überhaupt möglich, mit einer CODESYS-User-Applikation einen derartigen Fehler zu programmieren, dass das System komplett einfriert?
    Das wäre wichtig zu wissen, ob wir in unserer Applikation nach dem Fehler suchen müssen. Ich bin kein Experte für Linux-Systeme, aber meine Vorstellung wäre, dass ein Fehler in der User-Applikation im schlimmsten Fall den CODESYS-Prozess zum Absturz bringt. Aber wenn Linux komplett hängt, riecht das doch eher nach einem Problem in einem Treiber, der tiefer im System sitzt, oder?

    Hat die PFC200 eigentlich einen Hardware-Watchdog?
    Der Zustand, dass man einen Spannungsreset braucht ist wirklich recht unbequem. Nichtmal der Reset-Knopf tut etwas. (Der scheint ja auch nur ein Signal an die Software zu senden.)

    Hast du sonst noch Ideen oder Vorschläge dazu?

    Viele Grüße,
    Jan

    IMG: device_sates_normal1.png

    IMG: device_sates_crash1.PNG

     
  • eschwellinger

    eschwellinger - 2019-09-26

    Hi,
    kannst du mal noch in einem 2. Fenster
    tail -f /tmp/codesyscontrol.log
    machen und den Abstutz provuzieren?
    Ich denke wenn die Runtime crasht läuft Linux normal weiter (oder ist das nicht so?)

    Du schreibst noch was von KBUS meinst du damit die lokalen Klemmen am PFC oder hast du welche auch am CAN?

    Denke man könnte mal das Projekt reviewen... dazu musst du es an den CODESYS store schicken -> meine Frage
    klar wenn es dringend ist - Support ticket ist immer ne Option, dann schau ich mir es auch online an - egal wie es ausgeht.

    Grüße
    Edwin

     

Log in to post a comment.