Absturz Codesys

thommy54
2021-11-26
2021-12-09
  • thommy54 - 2021-11-26

    Hallo,

    auf einem Raspberry lief 1 Jahr stabil eine Anwendung. An dieser wird öfters geändert und seit ca. 14 Tagen stürzt Codesys ca. alle 6h ab.
    Ich habe mir erst mal geholfen, das ich Codesys automatisch neu starten lasse. Aber das kann ja nicht das Ziel sein.
    Nun ist es gerade eben im ONLINE-Modus abgestürzt und das erste Mal habe ich einen Hinweis bekommen.
    Ich kann mit dem Hinweis aber nichts anfangen (Bild).

    Wahrscheinlich bediene ich eine Library falsch o.ä. Gibt es noch für diesen Absturz, der ja recht geordnet zu verlaufen scheint, noch andere Logging-Quellen, die mir Hinweise geben könnten?

    Danke!

    Grüße
    Thomas

     
  • eschwellinger

    eschwellinger - 2021-11-27

    Immer zuerst ins SPS log schauen, entweder mit CODESYS (falls du noch online kommst) oder aber über ssh einloggen und dann:
    cat /tmp/codesyscontrol.log

    So generell um sowas zu finden würde ich immer empfehlen so vorzugehen:
    1. Implizite checks ausführen ob in der Applikation Array Überschreiber sind, mit checkbounds wir hier beschrieben:
    https://faq.codesys.com/pages/viewpage.action?pageId=3538982

    wenn das ok ist, dann:
    2.Auch mal schauen ob in in PLCLogic ein Application.core liegt. ( -> mit dem CODESYS File Browser)
    wenn da einer liegt mit dem Projekt analysieren:
    https://help.codesys.com/webapp/_cds_using_core_dump;product=codesys;version=3.5.17.0

    Grüße
    Edwin

     
  • thommy54 - 2021-11-27

    Hallo Edwin,
    vielen Dank für die Hinweise. Mit der Kontrollfunktion bezüglich der Arrays habe ich tatsächlich 2 Punkte gefunden, an denen ich unsauber mit dem Index umgegangen bin. Scheint aber nicht so richtig die Lösung zu sein. Nach den entsprechenden Änderungen kam erneut ein Absturz. Nur hatte ich jetzt ein Logfile /tmp/codesyscontrol.log .
    Ich habe einen Auszug als File angehängt. Ich kann insofern nicht viel daraus nehmen, das für mich ein expliziter Fehler nicht zu erkennen ist.
    Kannst Du eventuell was daraus erkennen ?

    Ein Application.core - File hat er nicht erstellt.

    Vielen Dank
    Thomas

     
  • thommy54 - 2021-11-27

    Ergänzung:
    Die Abstürze kommen relativ pünktlich alle 8h20min.
    In der Anwendung gibt es nichts mit so einem Zyklus.
    Beim letzten Absturz konnte ich in /tmp/codesyscontrol.log noch eine (vielleicht)interessante erste Zeile erkennen:

    2021-11-27T16:19:45Z, 0x0000007a, 2, 0, 0, !!!! Warning: CM SDK: : container 3-5362780 doesn't exist anymore
    

    War aber 3 Minuten vor dem Absturz.

    Grüße
    Thomas

     
  • eschwellinger

    eschwellinger - 2021-11-27

    mit key? Schau mal mit ssh 'top' ob der Speicher durch vielleicht ein memory leak aus geht.

     

    Last edit: eschwellinger 2021-11-27
  • thommy54 - 2021-11-27

    Ja ist ein Pi 4 mit key (USB-Stick).

     
  • thommy54 - 2021-11-27

    Der Top-Befehl sieht nicht nach Überlauf oder memory-leak aus (jedenfalls was ich erkennen kann):

    top - 22:28:46 up 3 days, 10:53,  2 users,  load average: 0,86, 0,55, 0,39
    Tasks: 116 total,   1 running, 115 sleeping,   0 stopped,   0 zombie
    %Cpu(s):  1,4 us,  0,7 sy,  0,0 ni, 97,9 id,  0,0 wa,  0,0 hi,  0,0 si,  0,0 st
    MiB Mem :   3906,0 total,   3255,2 free,    143,1 used,    507,6 buff/cache
    MiB Swap:    100,0 total,    100,0 free,      0,0 used.   3602,9 avail Mem
    
      PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
     6468 root      20   0   47580  35796   3960 S  32,8   0,9 103:41.93 codesysco+
    14836 root      20   0   10416   3080   2552 R   0,3   0,1   0:00.07 top
        1 root      20   0   33788   8032   6372 S   0,0   0,2   0:11.14 systemd
        2 root      20   0       0      0      0 S   0,0   0,0   0:00.26 kthreadd
        3 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 rcu_gp
        4 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 rcu_par_gp
        8 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 mm_percpu+
        9 root      20   0       0      0      0 S   0,0   0,0   3:17.52 ksoftirqd+
       10 root      20   0       0      0      0 I   0,0   0,0   4:05.84 rcu_sched
       11 root      20   0       0      0      0 I   0,0   0,0   0:00.00 rcu_bh
    
     
  • thommy54 - 2021-11-28

    Hallo Edwin,
    hier noch ein Log-Ausdruck, der mich nun ganz nervös macht.

    2021-11-28T08:49:46Z, 0x00000002, 1, 0, 2, Application [<app>Application</app>] loaded via [OnlineChange]
    2021-11-28T08:55:05Z, 0x0000007a, 2, 0, 0, !!!! Warning: CM SDK: : container 3-5362780 doesn't exist anymore
    
    2021-11-28T08:55:05Z, 0x00000001, 2, 0, 0, !!!! Warning: no runtime license - running in demo mode(~120 minutes)
    
    2021-11-28T08:55:05Z, 0x00000001, 1, 0, 35, CODESYS Control shutdown...
    2021-11-28T08:55:05Z, 0x00000071, 1, 0, 13, Webserver stopped
    2021-11-28T08:55:05Z, 0x00001019, 1, 16842752, 0, Reset Driver
    

    Sollte doch die Ursache ein Beenden wegen mangelnder Lizenz gemacht werden ???

    Etwas weiter im Logfile steht dann:

    2021-11-28T08:56:09Z, 0x0000100c, 1, 0, 0, Visu_PRG: Creating Client for Extern-ID: 647803
    2021-11-28T08:56:09Z, 0x0000100c, 1, 0, 0, Visu_PRG: Creating Client successful for Extern-ID: 647803 Returned IEC-ID: 0
    2021-11-28T08:57:08Z, 0x00000001, 1, 0, 0, runtime licensed
    

    Wenn der Prozess geordnet abgefahren wird (...CODESYS Control shutdown...), wo soll ich da noch suchen.

    Bin ziemlich ratlos. Es dauert ja auch alles ewig, da die Abstürze nur alle 8h20Min. stattfinden.

    Grüße
    Thomas

     
  • eschwellinger

    eschwellinger - 2021-11-28

    hm..ist komisch sieht aus als waere der Dongle sporadisch weg.
    Welche Pi runtime version verwendest du?
    mach mal lsusb, wenn es passieet ist, schauen ob der wibu key noch sichtbar ist fuer das OS.
    Welche Pi OS version verwendest du?

     
  • thommy54 - 2021-11-28

    der lsusb-Befehl bringt:

    root_pi4> lsusb
    Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
    Bus 001 Device 003: ID 064f:2af9 WIBU-Systems AG CmStick (HID, article no. 1001-xx-xxx)
    Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
    Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
    root_pi4>
    

    Codesys war gerade wieder zu Ende gekommen. 8h20min seit dem letzten Mal.

    Betriebssystem-Version:

    root_pi4> cat /etc/os-release
    PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
    NAME="Raspbian GNU/Linux"
    VERSION_ID="10"
    VERSION="10 (buster)"
    VERSION_CODENAME=buster
    ID=raspbian
    ID_LIKE=debian
    HOME_URL="http://www.raspbian.org/"
    SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
    BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
    root_pi4>
    

    Ich habe bei der Installation des Pi4 das Betriebssystem gedowngradet:

    sudo rpi-update e1050e94821a70b2e4c72b318d6c6c968552e9a2
    

    Da haben wir schon mal zusammen gegen Abstürze gekämpft:

    https://forge.codesys.com/forge/talk/Deutsch/thread/ef5dccd8ce/
    

    Und seitdem lief der Pi4 1 1/4 Jahre ohne Probleme durch. Mullticore und Multitasking und was weiss ich nicht alles, habe ich da losgelassen. Und seit ca. 14Tagen stürzt er ab.

    Das der Dongel den USb-Kontakt verliert, kann ich nicht ganz glauben, da er das immer genau im Rythmus von 8h20 Minuten machen müsste.
    Ich habe bestimmt irgendwelchen Quatsch reinprogrammiert. Nur finde ich diesen Quatsch eben nicht. Array-Überlauf habe ich auch anfangs gedacht. Aber nach dem "POU für implizite Prüfungen" sollte da auch alles gegessen sein, was an Unsauberkeiten drin war.

    Vielleicht ist auch irgendwas mit den Bibliotheken schief gegangen.
    Aber compilieren geht ja.

    Ich weiss nicht, ob man dem /tmp/codesyscontrol.log was sinniges entnehmen kann. Ich kanns nicht. Aber da aus meiner Sicht ein kontrolliertes Abfahren erfolgt, müsste codesys doch irgendwelche Crash-Informationen liefern.

    Das ist vielleicht ein toller 1. Advent...

    Viele Grüße
    Thomas

     
  • eschwellinger

    eschwellinger - 2021-11-28

    wenn du ne 2. SD hast mach doch ein aktuelles neues OS. dann alles drauf und dann sehen wir. Welche runtime version hast du am laufen?

     

    Last edit: eschwellinger 2021-11-28
  • thommy54 - 2021-11-29

    Bin gerade dabei, den Raspberry 4 freizuschaufeln und die Anwendung auf einen noch vorhandenen Raspberry 2 umzulegen. Ich muss meine Anwendung irgendwie am Leben erhalten. Leider geht das auch nicht ganz problemlos.
    Dann werde ich von vorn anfangen.

    Allerdings: Ich habe schon kurz nach dem ersten Auftreten des Problems ein Backup auf die SD-Karte vom Sommer gezogen und dann mein aktuelles Codesys-Programm aufgespielt. Das hat auch nichts gebracht - deswegen meine Befürchtung, das irgendwas im Programm foul spielt.

    Ich werde nun das neueste Raspbian installieren und dann weitersehen.

    Grüße
    Thomas

     
  • thommy54 - 2021-12-03

    Hallo Edwin,
    melde mich nach einem Auf und Ab des Erfolgslevels. Noch stürzt der Raspberry immer wieder ab.
    Ich hatte aber nochmal meine Codesys-Installation überprüfen wollen und einfach mal ein Example auf den Rasp gebracht. Und siehe da. das Programm lief durch. Nun habe ich Stück für Stück ein neues Projekt angelegt und bis zur Hälfte der zu übernehmenden Programmteile lief es gut. Keine Abstürze.
    Ungeduldig wie ich bin, hab ich gestern die letzten Teile übernommen - prompt stürzte Codesys nach 8h20Min. wieder ab.
    Der Absturz ist wie schon erwähnt, ziemlich koordieniert.

    2021-12-03T13:20:55Z, 0x0000007a, 2, 0, 0, !!!! Warning: CM SDK: : container 3-5362780 doesn't exist anymore
    2021-12-03T13:21:06Z, 0x00000059, 8, 81, 0, #### Exception: *EXCEPTION* in CommCycleHook <IP>0xb6cc4d90</IP> <BP>0x0</BP> <SP>0xb5471d10</SP>
    2021-12-03T13:21:06Z, 0x00000059, 65544, 81, 0, **** the system may be in an inconsistent state  performing shutdown! 
    2021-12-03T13:21:07Z, 0x00000001, 1, 0, 35, CODESYS Control shutdown...
    2021-12-03T13:21:07Z, 0x00000071, 1, 0, 13, Webserver stopped
    2021-12-03T13:21:07Z, 0x00001019, 1, 16842752, 0, Reset Driver
    2021-12-03T13:21:07Z, 0x00000071, 2, 0, 14, !!!! Warning: Unbalanced calls to WebServerRequestRunning/WebServerReleaseRunning
    2021-12-03T13:21:09Z, 0x00000018, 1, 0, 5, Network interface <interface>BlkDrvTcp</interface> unregistered
    2021-12-03T13:21:10Z, 0x00000124, 1, 0, 0, Provider CmpOPCUAProviderIecVarAccess with Version 0x305100a unregisterd at the OPC UA server.
    2021-12-03T13:21:10Z, 0x00000124, 1, 0, 0, Provider CODESYS_DefaultProvider with Version 0x3051000 unregisterd at the OPC UA server.
    2021-12-03T13:21:10Z, 0x00000124, 1, 0, 0, ********************** Server OPC UA stopped! *************************
    

    Besonders die Zeile:

    2021-12-03T13:21:06Z, 0x00000059, 8, 81, 0, #### Exception: *EXCEPTION* in CommCycleHook <IP>0xb6cc4d90</IP> <BP>0x0</BP> <SP>0xb5471d10</SP>
    

    müsste doch irgendeinen Hinweis geben, wo ich konkreter suchen kann.

    Hast Du dazu irgendwelche Infos ?

    Unter ~~~
    https://forge.codesys.com/forge/talk/Runtime/thread/e82256d0d8/
    ~~~

    wird ebenfalls ein Absturzverhalten beschrieben. Leider ist das dortige Problem wohl etwas anders gelagert.

    Viele Grüße
    Thomas

     
  • eschwellinger

    eschwellinger - 2021-12-03

    nein, hilft leider so nicht weiter,
    das mit checkbounds hast du wirklich gemacht?

     
  • thommy54 - 2021-12-03

    Ja habe ich gemacht, siehe oben:

    ...Mit der Kontrollfunktion bezüglich der Arrays habe ich tatsächlich 2 Punkte gefunden, an denen ich unsauber 
    mit dem Index umgegangen bin... 
    

    .
    .

    Ich dachte nur, die Fehlerausschrift im Logfile muss ja jemand mal programmiert haben.

    #### Exception: *EXCEPTION* in CommCycleHook <IP>0xb6cc4d90</IP>
    

    Und bei Euch muss doch sowas dokumentiert sein.
    Aber da scheine ich wohl Pech zu haben.

    Also weiter forschen. Ich kann nicht akzeptieren, dass das Teil alle reichlich 8h abstürzt.

    Danke und viele Grüße
    Thomas

     
  • thommy54 - 2021-12-09

    Hallo Edwin,
    es ist vollbracht. Ich habe die Absturzursache gefunden. Und wie so oft, bin ich selbst dran schuld. Es war kein Array was überläuft, sondern der Zugriff auf ein File war unsauber programmiert, so da es am Codesys hängenblieb und irgendwann die vielen Filezugriffen eins der "ulimits" überschritt. Für mich ist es nicht erfahrbar, ob dann Codesys selbst gesagt hat - ich gebe auf - oder ob Linux den Prozess gekillt hat.

    So sieht das im Betriebssystem dann aus:

    lsof -p 508  (508 ist PID des codesyscontrol-Prozesses)
    
    codesysco 508 root   28u   REG  179,2      182     399996 /root/Rasp_SPS_Filesystem/von_sps.txt (deleted)
    codesysco 508 root   29u   REG  179,2      182     400094 /root/Rasp_SPS_Filesystem/von_sps.txt (deleted)
    codesysco 508 root   30u   REG  179,2      182     400100 /root/Rasp_SPS_Filesystem/von_sps.txt (deleted)
    
    (und noch Hunderte gleiche Zeilen)
    ...
    ...
    

    Es waren beim Absturz so um die 1040 Zeilen mit dem Befehl

    lsof -p 508 | wc -l
    

    Das Programmierproblem war ein doppeltes SysFileOpen

    handle := SysFileOpen(SysFileName, am:=Sysfile.AM_APPEND_PLUS,pResult:=ADR(rtsResult));
    

    und ein ganzes Stück entfernt:

    handle := SysFileOpen(SysFileName, SysFile.AM_APPEND,pResult:=ADR(rtsResult));      (* Datei öffnen bzw. generieren *)      
            Written_Read_Bytes:=SysFileWrite(handle,pointer_to_array,length_of_array,pResult:=ADR(rtsResult));
            file_ok := SysFileClose(handle);                        (* Datei schließen *)
            SysFileLength:=SysFileGetSize(SysFileName,pResult:=ADR(rtsResult));
    

    Das erste SysFileOpen passt eben gar nicht dazu und muss mal "irgendwie" reingekommen sein.
    wahrscheinlich wollte ich mal was zusammenfassen oder sonstwas.

    Nachdem ich besagte Zeile entfernt habe liegt das Ergebnis von lsof -p 508 | wc -l jetzt bei ca. 55 .

    Wie bin ich daraufgekommen:

    In einem eigenen Logfile eines "expect"-scripts fand ich folgende Ausschrift:

    mount:  NAS-Dirs vorhanden
    spawn sftp p861233@home45675558.1and1-data.host
        too many programs spawned?  could not create pipe: **too many open files**
        while executing
        "spawn sftp p861233@home45675558.1and1-data.host"
    ls: cannot access '../von_sps.txt': No such file or directory
    

    Von da an war es nur noch etwas googeln und suchen im Programm.

    Und jetzt natürlich die Wünsche an Eure Programmierer (auch wenn sie sie nie erreichen):

    1. Die Ausschrift too many open files hätte vielleicht schon im Codesys-Logfile kommen können ?? Dann wäre die Suche erheblich vereinfacht gewesen.
    2. Warum wird ein 2. SysfileOpen auf ein offenes File überhaupt noch durchgeführt? Das führt doch immer zu Problemen - glaube ich. Eine Fehlerrückgabe und Rücksprung ohne Abarbeitung wäre doch da angebracht.

    Wie auch immer - ich bin froh, das das Programm jetzt nicht mehr nur 8h20Min. läuft.

    Ich danke Dir für Dein Mitsuchen und hoffe, das ich vielleicht wenigstens einem(!) Anderen helfe, so einen Programmierfehler zu finden.

    Viele Grüße
    Thomas

    PS.: ich weiss nicht, wie man die Überschrift dieses Topics ändern kann. Aber "Absturz Codesys" klingt jetzt für mich regelrecht falsch. Müsste heissen: "Absturz Codesys programmiert..."😇

     

Log in to post a comment.