Business Script was NAS herunterfährt, wenn das Backup erfolgreich ist?

[Zottelhias]

@Tommes
Zunächstmal wollte ich etwas kleiner Anfangen. Ja, es ist mir nur erstmal wichtig, es prüfen zu können.
Wenn das Script dann funktioniert hat, ist durchaus ein Gedanke die Maschine Herunterzufahren und wenn es nicht funktioniert einen neuen Schubs zu geben, dass die die Aufgabe nochmals ausgeführt wird.
Man könnte das aber auch verketten mit unterschiedlichen Aufgaben. Wie bspw. zuvor noch die Papierkörbe zu leeren. Oder danach noch einen Virenscan durchzuführen oder ein WOL an die anderen Clients zu schicken, um die auch zu Backupen, wenn der eine Task beendet ist.

Wie gesagt, erstmal will ich klein Anfangen.

 

[Tommes]

Da ich wenig scripting Erfahhrung habe…

… halte ich dein Vorhaben für sehr ambitioniert, auch wenn du…

…etwas kleiner Anfangen…

… wolltest, was durchaus Sinn macht. Ich will deine Fähigkeiten damit auch nicht in Frage stellen, da jeder von uns mal klein angefangen hat. Aber das, was du da vor hast, ist schon recht komplex bzw. könnte es mal werden. Da juckt es mir ja schon wieder in den Fingern, mir das mal näher anzuschauen, obwohl ich selbst, wie gesagt, nicht mit Active Backup arbeite. Vielleicht schau ich mir am WE mal an, wie so ein Prozess von Active Backup aussieht, oder was man mit dem Tipp von @luddi so anstellen kann. Die Logfiles auszuwerten, halte ich da eher für weniger sinnvoll, schau ich mir ggfl. aber auch mal an.

Aber wie gesagt… eventuell und… erwarte mal nicht zu viel von mir. Aber das Thema ist nicht ganz uninteressant.

 

[Zottelhias]

@Tommes

Aber wie gesagt… eventuell und… erwarte mal nicht zu viel von mir. Aber das Thema ist nicht ganz uninteressant.

Ohne dich einbremsen zu wollen, es geht mir nicht darum das mir das jemand schreiben soll. Ich wollte das selber machen und mir nur Tipps holen, wo ich die ein oder anderen Infos zusammentragen kann.

… wolltest, was durchaus Sinn macht. Ich will deine Fähigkeiten damit auch nicht in Frage stellen, da jeder von uns mal klein angefangen hat.

Genau, kleiner. Ich erwarte nicht sofort das alles funktioniert. Ich gehe meist einen sehr harten weg.

Aber das, was du da vor hast, ist schon recht komplex bzw. könnte es mal werden.

Ja, es kann sehr komplex werden. Aber ich glaube das zwei Infomationen zu verarbeiten erstmal nicht so komplex wird - wer nicht wagt, der nicht gewinnt.


Vielleicht wissen andere mehr dazu, wo ABFB die Erfolgreich-Meldungen ablegt bzw. Protokolliert.

 

[Tommes]

Ohne dich einbremsen zu wollen...

... ich halt ja schon die Füße still, setz mich auf meine Hände und halte den Babbel

Ich finde den Weg über den Aufgabenplaner, den @luddi dir vorgeschlagen hat, eigentlich sehr sympathisch und habe damit grade mal ein wenig herumgespielt. Ich konnte über eine while Schleife den Task zwar im Hintergrund überwachen und so bestimmen, ob der Task grade läuft oder nicht, jedoch habe ich auf die Schnelle keine Möglichkeit gefunden, herauszufinden, ob bzw. wann der Task erfolgreich abgearbeitet wurde und ob der Remote-Server nun runter fahren soll, oder nicht. Dafür bräuchte man zumindest sowas wie einen Timestamp, oder eine Erfolgsmeldung... was uns wieder zu dem von dir gesuchten Protokoll über Erfolgs- bzw. Misserfolgsmeldungen bringt.

Wie gesagt, da ich ABFB nicht nutze, ist für mich der Weg hier sowieso zuende. Ich könnte dir nur meine App "LogAnalysis" an die Hand geben (siehe meine Signatur) mit der du dich auf die Suche nach solchen Log-Einträgen machen könntest. Die App greift dabei aber nur auf den Log-Ordner /var/log zu. Sollte ABFB dort etwas ablegen, solltest du fündig werden. Bestenfalls taucht das alles in der var/log/messages auf.

Am Ende wird dich, nach meinen jetzigen Überlegungen, wohl eine Kombination aus beiden deinem Ziel näher bringen. Also zum einen die Auswertung des Task und zum Anderen die Auswertung entsprechender Protokolle.

Dann wünsche ich dir viel Erfolg bei deinem Vorhaben und vielleicht teilst du deine Erfolge ja irgenwann mit uns. Gerne auch in diesem Thread

Tommes

 

[Zottelhias]

... ich halt ja schon die Füße still, setz mich auf meine Hände und halte den Babbel

Wie gesagt, es geht mir nicht darum dass mir jemand etwas vorfertigt und dass dann so rüberkommt, als ob ich nur vorgekautes essen wolle und ich wollte dich auch nicht kränken, in dem ich dich wie auch immer geartet einbremse.

Ich finde den Weg über den Aufgabenplaner, den @luddi dir vorgeschlagen hat, eigentlich sehr sympathisch und habe damit grade mal ein wenig herumgespielt.

Den Weg via Taskplaner ist super. Ist auch meine erste wahl. Dort kann man ja ein Script einbinden und Zeitgesteuert ausführen lassen.

while Schleife den Task zwar im Hintergrund überwachen und so bestimmen, ob der Task grade läuft oder nicht

Das ist der entscheidende Punkt beim Task. Das wird nicht gehen. Wieso soll der Infos enthalten, dass der Erfolgreich war. Er bildet lediglich ab, das gegenwärtig dieser Task/Prozess läuft. Einen Status wird man da nicht finden. Ich lasse mich aber gerne eines Besseren belehren.
Daher auch mein Ansatz mit mit dem Protokoll.
Mit der von dir Benutzen While schleife habe auch ich begonnen. Stand jetzt, ohne das Script getestet zu haben, oder deren Richtigkeit sicher einschätzen zu können und wissentlich darüber, dass es noch nicht vollständig ist, bin ich derzeit hier:

# !/bin/bash

# Editor: Notepad++

# Der Kommentar zum Befehl und seiner erwateten Folge ist immer über dem Befehl.

# Variable anlegen, die den Status des Backups abfrägt.
# var...: Kennzeichnet die Variable/n, ... steht Stellvertretend für einen Beschreibungstext zu/r Variabele/n.
# grep: Ist der Befehl, der zur Suche nach einem Wort oder einer Wortkette benutzt werden kann.
# ERFOLGREICH oder SUCCESSFUL oder SUCCESSFULLY: Ist/Sind der/die Suchbegriff/e.
# Pfad/ABFB/Protokoll.xyz: Ist der Pfad zur Datei, in der gesucht werden soll.
varErfolgreich=grep ERFOLGREICH Pfad/ABFB/Protokoll.xyz
varSuccessful=grep SUCCESSFUL Pfad/ABFB/Protokoll.xyz
varSuccessfully=grep SUCCESSFULLY Pfad/ABFB/Protokoll.xyz

# Die While-Schlefe soll prüfen, ob eine der Bedingungen:
# "ERFOLGREICH",
# "SUCCESSFULL" oder
# "SUCCESSFULLY"
# im Protokoll von ABFB vorhanden ist.
while [ $varErfolgreich == "Erfolgreich" -o $varSuccessful == "Successful" -o $varSUCCESSFULLY == "Successfully" ]

    # Etnhält weitere Anweisungen wenn die Bedingungen zutreffend sind.
    do
        # Variable mit dem Text-Hinweis, dass das System in 5 min. (300 sek.) Heruntergefahren wird.
        varCountdownHerunterfahren300SekNAS01="Das NAS wird in 5 min. Heruntergafahren! Bitte beenden Sie alle ungespeicherten Anwendungen."
        
        # Es soll ein Text zurück gegeben werden, dass die Syno in 5 min. (300Sek) Heruntergefahren wird.
        # Das Vorgehen, wie das umgesetzt werden kann, muss noch geklärt werden.
        # Die Benachrichtigung soll im Benachrichtigungsfesnter bei allen Benutzern wiedergegeben werden.
        # Die folgende Zeile so lange Auskommentiert, bis klar ist, wie das Umgesetzt werden kann.
        # BenachrichtigungszentraleSyno $varCountdownHerunterfahren300SekNAS01
        
        # Countdown 300 Sek. (5 min.) erzwingt an der Stelle eine 5 min. Pause, bevor das System heruntergefahren wird.
        sleep 300s
        
        # Befehl zum Herunterfahren der NAS, wenn alles zutreffend ist und die 300 sek. abgelaufen sind.
        shutdown --poweroff
    done

Was noch wissentlich offen ist:
1. Ich kenne den Pfad zu der Datei mit der ich einen Vergleich anstellen kann noch nicht
2. Ich weis noch nicht, wie ich eine Benachrichtigung über die Benachrichtigungszentrale ausgeben kann, so das Benutzer informiert werden.

Was unwissentlich offen oder falsch oder von mir übersehen wurde ist - da bin ich auf euch angewiesen:
1. ...
2. usw.

Hinweise, wo ich eventuell die Erfolgsmeldungen herausfiltern kann, nehme ich immer gerne an und sind Ausdrücklich WILLKOMMEN!

 

[Zottelhias]

Eventuell habe ich mir eben selbst einen Hinweis gegeben. Die Benachrichtigungszentrale könnte ein Ansatz sein. Werde ich, sobald ich wieder Zeit habe, Prüfen.

@luddi
@Tommes
Das mit der Task-Prüfung sehe ich als kontrolle an, ob der Prozess noch aktiv ist. Das sollte in den Entwurf von meinem Script noch mit einfließen. Denn es ist ja so: nur weil ich mit der Prüfung sicherstellen kann, dass das Backup erfolgreich ist, muss der Prozess noch nicht abgeschlossen sein.

 

[Tommes]

Dann poste ich mal mein oberflächliches sowie absolut unvollkommenes Script zur Task-Prüfung, womit ich heut morgen rumgespielt habe. Das einzige, was man angeben muss, ist die ID des Task, welcher überwacht werden soll.

#!/bin/bash

id="4"

task=$(synoschedtask --get id=${id})
name=$(echo "${task}" | grep "Name" | cut -d ":" -f2 | cut -d '[' -f2 | cut -d ']' -f1 )
status=$(echo "${task}" | grep "Status" | cut -d ":" -f2 | cut -d '[' -f2 | cut -d ']' -f1 )
pid=$(echo "${task}" | grep "Pid" | cut -d ":" -f2 | cut -d '[' -f2 | cut -d ']' -f1 )

#status="Running"

if [[ "${status}" == "Not Available" ]]; then
   echo 'Die Aufgabe ['${name}'] wird zur Zeit nicht ausgeführt'
elif [[ "${status}" == "Running" ]]; then
   echo 'Die Aufgabe ['${name}'] wird ausgeführt. Die Prozess-ID lautet: '${pid}''
   while sleep 1; do
      if [ -z "${pid}" ]; then
         echo 'Die Aufgabe ['${name}'] wurde ausgeführt. Der Remote-Server wird heruntergefahren'
         break
      fi
   done &
fi

Du könntest die Prozess-ID (pid) auch dafür verwenden, den Prozess mit ps weiter zu verfolgen, je nachdem.

Ups: Da fehlte noch ein Hochkomma hinter '${pid}'

 

[luddi]

echo "${task}" | grep "Pid"

Hi @Tommes ich wollte mal an dieser Stelle nach der Pid nachfragen.

Bei meinen Aufgaben gibt es kein "Pid" Atrribut wenn ich synoschedtask --get aufrufe. Aus welchem Grund sehe ich das nicht?

Edit:
Ach klar.... natürlich sehe ich dies nur wenn sich der Task im Status running befindet.

synoschedtask --get id=<ID> running=true

 

[Tommes]

Schau dir mal in deinen Beitrag #13 die zweite Codebox an, dort steht ganz unten…

$ synoschedtask --get running=true
             User: [root]
               ID: [41]
             Name: [NextCloud <Instance_XXX> cron.php]
            State: [enabled]
            Owner: [root]
             Type: [daily]
       Start date: [0/0/0]
         Run time: [0]:[0]
Repeat every [5] min (s) until [23]:[55]
          Command: [/bin/su -s /bin/sh -c "/usr/local/bin/php80 -f /var/services/web/nextcloud/<instance_xxx>/cron.php" http]
    Last Run Time: Thu Jan 19 14:50:01 2023
           Status: [Running]
              Pid: [22351]

… dort steht die Pid, sobald die Aufgabe ausgeführt wird und somit der Status auf [Running] steht.

 

[luddi]

Hat sich erledigt, siehe Edit. Danke dir!

 

[Tommes]

Wie gesagt, dem Script fehlt noch die Logik, ist also nur als Gedankenstütze anzusehen. Die Pid Auswertung müsste z.B. auch innerhalb der while Schleife abgefragt werden, damit das Sinn macht… usw.

 

[Zottelhias]

Also es scheint als ob ich das Log gefunden habe. Es liegt im folgenden Verzeichnis:

/var/packages/ActiveBackup/target/log/agent$

und trägt den Namen:
active-backup-agent.log

Der Vollständige Auszug vom gestrigen Tag (31.01.2023) des Logs sieht wie folgt aus - die Zeilen mit dem Datum- / Uhrzeit-Wert "Jan 31 23:15:19" und die letzte Zeile beginnent mit "Jan 31 23:21:57" sind mir aufgefallen:

Jan 31 00:00:01 +0100 [INFO] miss-schedule-handler.cpp:93(25748,139934739269376) MissScheduleNotifyHandler Start
Jan 31 08:00:05 +0100 [WARNING] master-server-impl-default.cpp:296(25566,139935143529984) Sync daemon is stopping...
Jan 31 08:00:05 +0100 [INFO] process-worker-server.cpp:275(25749,139935143529984) ProcessWorkerServer receives stop command
Jan 31 08:00:05 +0100 [INFO] process-worker-server.cpp:219(25749,139935143529984) ProcessWorkerServer::MainLoop() state is not STATE_RUNNING '2'
Jan 31 08:00:05 +0100 [INFO] thread-worker-server.cpp:181(25749,139935143529984) ThreadWorkerServer::Stop() called '0x7f4532cc1a10'
Jan 31 08:00:06 +0100 [INFO] sync-server.cpp:605(25749,139934722483968) Stop: set abort_flag
Jan 31 08:00:06 +0100 [INFO] server-system-db.cpp:367(25749,139934722483968) LogDB has been deinitialzed
Jan 31 08:00:06 +0100 [INFO] sync-server.cpp:605(25749,139934722483968) Stop: set abort_flag
Jan 31 08:00:06 +0100 [WARNING] stream.cpp:1206(25566,139935143529984) Channel: -2
Jan 31 08:00:06 +0100 [ERROR] stream.cpp:1823(25566,139935143529984) Error stack:
Jan 31 08:00:06 +0100 [ERROR] master-server.cpp:183(25566,139935143529984) Failed to recv to PObject (maybe the process is being recycled)
Jan 31 08:00:06 +0100 [INFO] process-worker-server.cpp:275(25748,139935143529984) ProcessWorkerServer receives stop command
Jan 31 08:00:06 +0100 [INFO] process-worker-server.cpp:219(25748,139935143529984) ProcessWorkerServer::MainLoop() state is not STATE_RUNNING '2'
Jan 31 08:00:06 +0100 [INFO] thread-worker-server.cpp:181(25748,139935143529984) ThreadWorkerServer::Stop() called '0x7f4532cc1a10'
Jan 31 08:00:08 +0100 [INFO] server-system-db.cpp:367(25748,139934705698560) LogDB has been deinitialzed
Jan 31 08:00:08 +0100 [WARNING] stream.cpp:1206(25566,139935143529984) Channel: -2
Jan 31 08:00:08 +0100 [ERROR] stream.cpp:1823(25566,139935143529984) Error stack:
Jan 31 08:00:08 +0100 [ERROR] master-server.cpp:183(25566,139935143529984) Failed to recv to PObject (maybe the process is being recycled)
Jan 31 08:00:08 +0100 [WARNING] syncd.cpp:454(25566,139935143529984) Sync daemon stop.
Jan 31 23:15:09 +0100 [INFO] server-system-db.cpp:338(23949,140522899676672) SystemDB has been initialized with location '/volume1/@ActiveBackup/agent/system-db.sqlite'
Jan 31 23:15:09 +0100 [INFO] server-system-db.cpp:367(23949,140522899676672) LogDB has been deinitialzed
Jan 31 23:15:09 +0100 [INFO] syncd.cpp:204(23949,140522899676672) Max process: '31'. Max connections per process: '128'
Jan 31 23:15:09 +0100 [WARNING] syncd.cpp:452(23949,140522899676672) Sync daemon starts...
Jan 31 23:15:10 +0100 [INFO] master-server-impl-default.cpp:446(23949,140522899676672) MasterServerImplDefault: spawning a new process service server worker '0x7fce0af68430'
Jan 31 23:15:10 +0100 [INFO] master-server-impl-default.cpp:612(23949,140522899676672) Spawn a new sync worker since the number of sync worker is not enough: '0' < '1'
Jan 31 23:15:10 +0100 [INFO] master-server-impl-default.cpp:521(23949,140522899676672) MasterServerImplDefault: spawning a new process sync server worker '0x7fce0af64c30'
Jan 31 23:15:10 +0100 [INFO] master-server-impl-default.cpp:778(23949,140522899676672) Spawned a new sync worker, finishing this adjust round
Jan 31 23:15:10 +0100 [INFO] server-system-db.cpp:338(24191,140522899676672) SystemDB has been initialized with location '/volume1/@ActiveBackup/agent/system-db.sqlite'
Jan 31 23:15:10 +0100 [INFO] server-system-db.cpp:338(24192,140522899676672) SystemDB has been initialized with location '/volume1/@ActiveBackup/agent/system-db.sqlite'
Jan 31 23:15:19 +0100 [INFO] service-control.cpp:661(24192,140522899502848) job add success, job content: {"action":1,"backup_type":5,"is_sub_jobs_init":false,"job_id":1,"job_type":1,"max_parallel":1,"params":{"device_id":3},"pid":24322,"status":8,"storage_id":3,"task_id":7,"trigger_uid":1034}
Jan 31 23:15:20 +0100 [INFO] running-task-monitor.cpp:2795(24191,140522419881728) running task start, running task id: 59, task id: 7, device_id: 3, job id: 1
Jan 31 23:15:20 +0100 [INFO] client-trigger-handler.cpp:693(24192,140522899502848) addBackupTask task id: 7, running_task_id: 59, job_id: 1, Job::Action: 1, DataFormat: 1, job_params: null
, trigger_type: 2, trigger_event: 0
Jan 31 23:17:21 +0100 [INFO] backup-handler.cpp:59(24192,140522894845696) In handler '13BackupHandler' with action 'backup'.
Jan 31 23:17:21 +0100 [INFO] backup-handler.cpp:60(24192,140522894845696)    request is {"action": "backup", "agent": {"version": {"build": "12420", "major": 2, "mini": 2, "minor": 4}}, "ds_id": "26340e4b-0f8a-4473-af1d-337c6ad8d36c", "enable_app_aware": 0, "resume": 0, "running_task_id": 59, "snapshot_info": {"data_length": 91351, }, "subaction": "update_device_spec", "token": "6d081966267b5211f150fafa5589e86b"}
Jan 31 23:17:21 +0100 [INFO] backup-handler.cpp:59(24192,140522470237952) In handler '13BackupHandler' with action 'backup'.
Jan 31 23:17:21 +0100 [INFO] backup-handler.cpp:60(24192,140522470237952)    request is {"action": "backup", "agent": {"version": {"build": "12420", "major": 2, "mini": 2, "minor": 4}}, "is_cache": 0, "running_task_id": 59, "subaction": "upload_block", "token": "6d081966267b5211f150fafa5589e86b"}
Jan 31 23:17:21 +0100 [INFO] disk-writer-helper.cpp:155(24192,140522470237952) new Disk Writer
Jan 31 23:17:26 +0100 [INFO] disk-writer-helper.cpp:168(24192,140522470237952) new Disk Writer over
Jan 31 23:17:26 +0100 [INFO] backup-workers.cpp:198(24192,140522456590080) BackupReadChannelWorker: start, running task id 59
Jan 31 23:17:26 +0100 [INFO] backup-workers.cpp:476(24192,140522448197376) BackupDecompressWorker: start, running task id 59
Jan 31 23:17:26 +0100 [INFO] backup-workers.cpp:671(24192,140522439804672) BackupWriteFileWorker: start, running task id 59
Jan 31 23:17:26 +0100 [INFO] backup-workers.cpp:767(24192,140522439804672) [DEDUP] open m_disk_writer_helper
Jan 31 23:17:26 +0100 [INFO] disk-writer-helper.cpp:438(24192,140522439804672) Disk Writer open file object_rel_path 'ActiveBackup_2023-01-31_231519/system-root.img', uuid 'system-root.img', file size '2549940224', resume_rel_path '', resume_postfix: '', base_version_id: '32', ref_rel_path: ''
Jan 31 23:17:26 +0100 [INFO] disk-writer-helper.cpp:449(24192,140522439804672) Disk Writer open file over
Jan 31 23:17:26 +0100 [INFO] disk-writer-helper.cpp:452(24192,140522439804672) Disk Writer open file, base_version_object: version_id(): '32', object_uuid(): 'system-root.img', backup_context_base_version: '32', current_object_uuid: 'system-root.img'
Jan 31 23:17:27 +0100 [INFO] disk-writer-helper.cpp:551(24192,140522439804672) disk writer close file, file path object_rel_path: ActiveBackup_2023-01-31_231519/system-root.img, postfix: , file size: 2549940224, blSuspend[0]
Jan 31 23:17:27 +0100 [INFO] disk-writer-helper.cpp:554(24192,140522439804672) disk writer close file over
Jan 31 23:17:27 +0100 [INFO] disk-writer-helper.cpp:782(24192,140522439804672) stream checkpoint, root path: /volume1/ActiveBackupforBusiness/@ActiveBackup
Jan 31 23:17:29 +0100 [INFO] disk-writer-helper.cpp:785(24192,140522439804672) stream checkpoint over
Jan 31 23:17:30 +0100 [INFO] backup-workers.cpp:767(24192,140522439804672) [DEDUP] open m_disk_writer_helper
Jan 31 23:17:30 +0100 [INFO] disk-writer-helper.cpp:438(24192,140522439804672) Disk Writer open file object_rel_path 'ActiveBackup_2023-01-31_231519/synorbd_2.img', uuid 'synorbd_2.img', file size '251122745344', resume_rel_path '', resume_postfix: '', base_version_id: '32', ref_rel_path: ''
Jan 31 23:17:30 +0100 [INFO] disk-writer-helper.cpp:449(24192,140522439804672) Disk Writer open file over
Jan 31 23:17:30 +0100 [INFO] disk-writer-helper.cpp:452(24192,140522439804672) Disk Writer open file, base_version_object: version_id(): '32', object_uuid(): 'synorbd_2.img', backup_context_base_version: '32', current_object_uuid: 'synorbd_2.img'Jan 31 08:00:05 +0100 [WARNING] master-server-impl-default.cpp:296(25566,139935143529984) Sync daemon is stopping...
Jan 31 08:00:05 +0100 [INFO] process-worker-server.cpp:275(25749,139935143529984) ProcessWorkerServer receives stop command
Jan 31 08:00:05 +0100 [INFO] process-worker-server.cpp:219(25749,139935143529984) ProcessWorkerServer::MainLoop() state is not STATE_RUNNING '2'
Jan 31 08:00:05 +0100 [INFO] thread-worker-server.cpp:181(25749,139935143529984) ThreadWorkerServer::Stop() called '0x7f4532cc1a10'
Jan 31 08:00:06 +0100 [INFO] sync-server.cpp:605(25749,139934722483968) Stop: set abort_flag
Jan 31 08:00:06 +0100 [INFO] server-system-db.cpp:367(25749,139934722483968) LogDB has been deinitialzed
Jan 31 08:00:06 +0100 [INFO] sync-server.cpp:605(25749,139934722483968) Stop: set abort_flag
Jan 31 08:00:06 +0100 [WARNING] stream.cpp:1206(25566,139935143529984) Channel: -2
Jan 31 08:00:06 +0100 [ERROR] stream.cpp:1823(25566,139935143529984) Error stack:
Jan 31 08:00:06 +0100 [ERROR] master-server.cpp:183(25566,139935143529984) Failed to recv to PObject (maybe the process is being recycled)
Jan 31 08:00:06 +0100 [INFO] process-worker-server.cpp:275(25748,139935143529984) ProcessWorkerServer receives stop command
Jan 31 08:00:06 +0100 [INFO] process-worker-server.cpp:219(25748,139935143529984) ProcessWorkerServer::MainLoop() state is not STATE_RUNNING '2'
Jan 31 08:00:06 +0100 [INFO] thread-worker-server.cpp:181(25748,139935143529984) ThreadWorkerServer::Stop() called '0x7f4532cc1a10'
Jan 31 08:00:08 +0100 [INFO] server-system-db.cpp:367(25748,139934705698560) LogDB has been deinitialzed
Jan 31 08:00:08 +0100 [WARNING] stream.cpp:1206(25566,139935143529984) Channel: -2
Jan 31 08:00:08 +0100 [ERROR] stream.cpp:1823(25566,139935143529984) Error stack:
Jan 31 08:00:08 +0100 [ERROR] master-server.cpp:183(25566,139935143529984) Failed to recv to PObject (maybe the process is being recycled)
Jan 31 08:00:08 +0100 [WARNING] syncd.cpp:454(25566,139935143529984) Sync daemon stop.
Jan 31 23:15:09 +0100 [INFO] server-system-db.cpp:338(23949,140522899676672) SystemDB has been initialized with location '/volume1/@ActiveBackup/agent/system-db.sqlite'
Jan 31 23:15:09 +0100 [INFO] server-system-db.cpp:367(23949,140522899676672) LogDB has been deinitialzed
Jan 31 23:15:09 +0100 [INFO] syncd.cpp:204(23949,140522899676672) Max process: '31'. Max connections per process: '128'
Jan 31 23:15:09 +0100 [WARNING] syncd.cpp:452(23949,140522899676672) Sync daemon starts...
Jan 31 23:15:10 +0100 [INFO] master-server-impl-default.cpp:446(23949,140522899676672) MasterServerImplDefault: spawning a new process service server worker '0x7fce0af68430'
Jan 31 23:15:10 +0100 [INFO] master-server-impl-default.cpp:612(23949,140522899676672) Spawn a new sync worker since the number of sync worker is not enough: '0' < '1'
Jan 31 23:15:10 +0100 [INFO] master-server-impl-default.cpp:521(23949,140522899676672) MasterServerImplDefault: spawning a new process sync server worker '0x7fce0af64c30'
Jan 31 23:15:10 +0100 [INFO] master-server-impl-default.cpp:778(23949,140522899676672) Spawned a new sync worker, finishing this adjust round
Jan 31 23:15:10 +0100 [INFO] server-system-db.cpp:338(24191,140522899676672) SystemDB has been initialized with location '/volume1/@ActiveBackup/agent/system-db.sqlite'
Jan 31 23:15:10 +0100 [INFO] server-system-db.cpp:338(24192,140522899676672) SystemDB has been initialized with location '/volume1/@ActiveBackup/agent/system-db.sqlite'
Jan 31 23:15:19 +0100 [INFO] service-control.cpp:661(24192,140522899502848) job add success, job content: {"action":1,"backup_type":5,"is_sub_jobs_init":false,"job_id":1,"job_type":1,"max_parallel":1,"params":{"device_id":3},"pid":24322,"status":8,"storage_id":3,"task_id":7,"trigger_uid":1034}
Jan 31 23:15:20 +0100 [INFO] running-task-monitor.cpp:2795(24191,140522419881728) running task start, running task id: 59, task id: 7, device_id: 3, job id: 1
Jan 31 23:15:20 +0100 [INFO] client-trigger-handler.cpp:693(24192,140522899502848) addBackupTask task id: 7, running_task_id: 59, job_id: 1, Job::Action: 1, DataFormat: 1, job_params: null
, trigger_type: 2, trigger_event: 0
Jan 31 23:17:21 +0100 [INFO] backup-handler.cpp:59(24192,140522894845696) In handler '13BackupHandler' with action 'backup'.
Jan 31 23:17:21 +0100 [INFO] backup-handler.cpp:60(24192,140522894845696)    request is {"action": "backup", "agent": {"version": {"build": "12420", "major": 2, "mini": 2, "minor": 4}}, "ds_id": "26340e4b-0f8a-4473-af1d-337c6ad8d36c", "enable_app_aware": 0, "resume": 0, "running_task_id": 59, "snapshot_info": {"data_length": 91351, }, "subaction": "update_device_spec", "token": "6d081966267b5211f150fafa5589e86b"}
Jan 31 23:17:21 +0100 [INFO] backup-handler.cpp:59(24192,140522470237952) In handler '13BackupHandler' with action 'backup'.
Jan 31 23:17:21 +0100 [INFO] backup-handler.cpp:60(24192,140522470237952)    request is {"action": "backup", "agent": {"version": {"build": "12420", "major": 2, "mini": 2, "minor": 4}}, "is_cache": 0, "running_task_id": 59, "subaction": "upload_block", "token": "6d081966267b5211f150fafa5589e86b"}
Jan 31 23:17:21 +0100 [INFO] disk-writer-helper.cpp:155(24192,140522470237952) new Disk Writer
Jan 31 23:17:26 +0100 [INFO] disk-writer-helper.cpp:168(24192,140522470237952) new Disk Writer over
Jan 31 23:17:26 +0100 [INFO] backup-workers.cpp:198(24192,140522456590080) BackupReadChannelWorker: start, running task id 59
Jan 31 23:17:26 +0100 [INFO] backup-workers.cpp:476(24192,140522448197376) BackupDecompressWorker: start, running task id 59
Jan 31 23:17:26 +0100 [INFO] backup-workers.cpp:671(24192,140522439804672) BackupWriteFileWorker: start, running task id 59
Jan 31 23:17:26 +0100 [INFO] backup-workers.cpp:767(24192,140522439804672) [DEDUP] open m_disk_writer_helper
Jan 31 23:17:26 +0100 [INFO] disk-writer-helper.cpp:438(24192,140522439804672) Disk Writer open file object_rel_path 'ActiveBackup_2023-01-31_231519/system-root.img', uuid 'system-root.img', file size '2549940224', resume_rel_path '', resume_postfix: '', base_version_id: '32', ref_rel_path: ''
Jan 31 23:17:26 +0100 [INFO] disk-writer-helper.cpp:449(24192,140522439804672) Disk Writer open file over
Jan 31 23:17:26 +0100 [INFO] disk-writer-helper.cpp:452(24192,140522439804672) Disk Writer open file, base_version_object: version_id(): '32', object_uuid(): 'system-root.img', backup_context_base_version: '32', current_object_uuid: 'system-root.img'
Jan 31 23:17:27 +0100 [INFO] disk-writer-helper.cpp:551(24192,140522439804672) disk writer close file, file path object_rel_path: ActiveBackup_2023-01-31_231519/system-root.img, postfix: , file size: 2549940224, blSuspend[0]
Jan 31 23:17:27 +0100 [INFO] disk-writer-helper.cpp:554(24192,140522439804672) disk writer close file over
Jan 31 23:17:27 +0100 [INFO] disk-writer-helper.cpp:782(24192,140522439804672) stream checkpoint, root path: /volume1/ActiveBackupforBusiness/@ActiveBackup
Jan 31 23:17:29 +0100 [INFO] disk-writer-helper.cpp:785(24192,140522439804672) stream checkpoint over
Jan 31 23:17:30 +0100 [INFO] backup-workers.cpp:767(24192,140522439804672) [DEDUP] open m_disk_writer_helper
Jan 31 23:17:30 +0100 [INFO] disk-writer-helper.cpp:438(24192,140522439804672) Disk Writer open file object_rel_path 'ActiveBackup_2023-01-31_231519/synorbd_2.img', uuid 'synorbd_2.img', file size '251122745344', resume_rel_path '', resume_postfix: '', base_version_id: '32', ref_rel_path: ''
Jan 31 23:17:30 +0100 [INFO] disk-writer-helper.cpp:449(24192,140522439804672) Disk Writer open file over
Jan 31 23:17:30 +0100 [INFO] disk-writer-helper.cpp:452(24192,140522439804672) Disk Writer open file, base_version_object: version_id(): '32', object_uuid(): 'synorbd_2.img', backup_context_base_version: '32', current_object_uuid: 'synorbd_2.img'
Jan 31 23:17:37 +0100 [INFO] disk-writer-helper.cpp:551(24192,140522439804672) disk writer close file, file path object_rel_path: ActiveBackup_2023-01-31_231519/synorbd_2.img, postfix: , file size: 251122745344, blSuspend[0]
Jan 31 23:17:37 +0100 [INFO] disk-writer-helper.cpp:554(24192,140522439804672) disk writer close file over
Jan 31 23:17:37 +0100 [INFO] disk-writer-helper.cpp:782(24192,140522439804672) stream checkpoint, root path: /volume1/ActiveBackupforBusiness/@ActiveBackup
Jan 31 23:17:40 +0100 [INFO] disk-writer-helper.cpp:785(24192,140522439804672) stream checkpoint over
Jan 31 23:17:53 +0100 [INFO] backup-workers.cpp:767(24192,140522439804672) [DEDUP] open m_disk_writer_helper
Jan 31 23:17:53 +0100 [INFO] disk-writer-helper.cpp:438(24192,140522439804672) Disk Writer open file object_rel_path 'ActiveBackup_2023-01-31_231519/synorbd_1.img', uuid 'synorbd_1.img', file size '11992474714112', resume_rel_path '', resume_postfix: '', base_version_id: '32', ref_rel_path: ''
Jan 31 23:17:53 +0100 [INFO] disk-writer-helper.cpp:449(24192,140522439804672) Disk Writer open file over
Jan 31 23:17:53 +0100 [INFO] disk-writer-helper.cpp:452(24192,140522439804672) Disk Writer open file, base_version_object: version_id(): '32', object_uuid(): 'synorbd_1.img', backup_context_base_version: '32', current_object_uuid: 'synorbd_1.img'
Jan 31 23:19:09 +0100 [INFO] backup-workers.cpp:270(24192,140522456590080) BackupReadChannelWorker: stop, running task id 59
Jan 31 23:19:09 +0100 [INFO] backup-workers.cpp:535(24192,140522448197376) BackupDecompressWorker: stop, running task id 59
Jan 31 23:19:09 +0100 [INFO] disk-writer-helper.cpp:551(24192,140522439804672) disk writer close file, file path object_rel_path: ActiveBackup_2023-01-31_231519/synorbd_1.img, postfix: , file size: 11992474714112, blSuspend[0]
Jan 31 23:19:09 +0100 [INFO] disk-writer-helper.cpp:554(24192,140522439804672) disk writer close file over
Jan 31 23:19:09 +0100 [INFO] disk-writer-helper.cpp:782(24192,140522439804672) stream checkpoint, root path: /volume1/ActiveBackupforBusiness/@ActiveBackup
Jan 31 23:19:13 +0100 [INFO] disk-writer-helper.cpp:785(24192,140522439804672) stream checkpoint over
Jan 31 23:19:13 +0100 [INFO] backup-workers.cpp:741(24192,140522439804672) BackupWriteFileWorker: stop, running task id 59
Jan 31 23:19:13 +0100 [INFO] backup-workers.cpp:547(24192,140522470237952) delete m_disk_writer_helper
Jan 31 23:19:13 +0100 [INFO] backup-handler.cpp:59(24192,140522899502848) In handler '13BackupHandler' with action 'backup'.
Jan 31 23:19:13 +0100 [INFO] backup-handler.cpp:60(24192,140522899502848)    request is {"action": "backup", "agent": {"version": {"build": "12420", "major": 2, "mini": 2, "minor": 4}}, "ds_id": "26340e4b-0f8a-4473-af1d-337c6ad8d36c", "result_id": 653, "running_task_id": 59, "status": "complete", "subaction": "check_complete", "token": "6d081966267b5211f150fafa5589e86b"}
Jan 31 23:19:16 +0100 [WARNING] stream.cpp:779(24192,140522470237952) Channel: -2
Jan 31 23:19:16 +0100 [ERROR] stream.cpp:1823(24192,140522470237952) Error stack:
Jan 31 23:19:16 +0100 [ERROR] sync-task.cpp:144(24192,140522470237952) Failed to write message header. (code: -2)
Jan 31 23:19:16 +0100 [INFO] running-task-monitor.cpp:1178(24191,140522068899584) RunningTaskMonitor:: get Running task 59 not in map
Jan 31 23:19:16 +0100 [INFO] service-control.cpp:694(24191,140522428274432) ServiceRemoveJobByJobId: 1
Jan 31 23:19:16 +0100 [INFO] running-task-monitor.cpp:2163(24191,140522428274432) === Transfer Performance ===
Jan 31 23:19:16 +0100 [INFO] running-task-monitor.cpp:2164(24191,140522428274432)    duration_ns 137000000000.000000
Jan 31 23:19:16 +0100 [INFO] running-task-monitor.cpp:2165(24191,140522428274432)    transfer_duration_ns 128101987105.000000
Jan 31 23:19:16 +0100 [INFO] running-task-monitor.cpp:2166(24191,140522428274432)    snapshot_ns 8898012895.000000
Jan 31 23:19:16 +0100 [INFO] running-task-monitor.cpp:2167(24191,140522428274432)    read_disk_ns 0.000000
Jan 31 23:19:16 +0100 [INFO] running-task-monitor.cpp:2168(24191,140522428274432)    send_ns 0.000000
Jan 31 23:19:16 +0100 [INFO] running-task-monitor.cpp:2169(24191,140522428274432)    dedup_ns 4242861999.000000
Jan 31 23:19:16 +0100 [INFO] running-task-monitor.cpp:2170(24191,140522428274432)    write_ns 3331945000.000000
Jan 31 23:19:17 +0100 [INFO] service-control.cpp:661(24192,140522468132608) job add success, job content: {"action":1,"backup_type":5,"is_sub_jobs_init":false,"job_id":2,"job_type":1,"max_parallel":1,"params":{"device_id":3},"pid":26535,"status":8,"storage_id":3,"task_id":7,"trigger_uid":1034}
Jan 31 23:19:17 +0100 [INFO] running-task-monitor.cpp:2795(24191,140522068899584) running task start, running task id: 60, task id: 7, device_id: 3, job id: 2
Jan 31 23:19:17 +0100 [INFO] client-trigger-handler.cpp:693(24192,140522468132608) addBackupTask task id: 7, running_task_id: 60, job_id: 2, Job::Action: 1, DataFormat: 1, job_params: null
, trigger_type: 5, trigger_event: 0
Jan 31 23:19:39 +0100 [INFO] backup-handler.cpp:59(24192,140522468132608) In handler '13BackupHandler' with action 'backup'.
Jan 31 23:19:39 +0100 [INFO] backup-handler.cpp:60(24192,140522468132608)    request is {"action": "backup", "agent": {"version": {"build": "12420", "major": 2, "mini": 2, "minor": 4}}, "ds_id": "26340e4b-0f8a-4473-af1d-337c6ad8d36c", "enable_app_aware": 0, "resume": 0, "running_task_id": 60, "snapshot_info": {"data_length": 91441, }, "subaction": "update_device_spec", "token": "6d081966267b5211f150fafa5589e86b"}
Jan 31 23:19:40 +0100 [INFO] backup-handler.cpp:59(24192,140522469185280) In handler '13BackupHandler' with action 'backup'.
Jan 31 23:19:40 +0100 [INFO] backup-handler.cpp:60(24192,140522469185280)    request is {"action": "backup", "agent": {"version": {"build": "12420", "major": 2, "mini": 2, "minor": 4}}, "is_cache": 0, "running_task_id": 60, "subaction": "upload_block", "token": "6d081966267b5211f150fafa5589e86b"}
Jan 31 23:19:40 +0100 [INFO] disk-writer-helper.cpp:155(24192,140522469185280) new Disk Writer
Jan 31 23:19:44 +0100 [INFO] disk-writer-helper.cpp:168(24192,140522469185280) new Disk Writer over
Jan 31 23:19:44 +0100 [INFO] backup-workers.cpp:476(24192,140522456590080) BackupDecompressWorker: start, running task id 60
Jan 31 23:19:44 +0100 [INFO] backup-workers.cpp:198(24192,140522439804672) BackupReadChannelWorker: start, running task id 60
Jan 31 23:19:44 +0100 [INFO] backup-workers.cpp:671(24192,140522448197376) BackupWriteFileWorker: start, running task id 60
Jan 31 23:19:44 +0100 [INFO] backup-workers.cpp:767(24192,140522448197376) [DEDUP] open m_disk_writer_helper
Jan 31 23:19:44 +0100 [INFO] disk-writer-helper.cpp:438(24192,140522448197376) Disk Writer open file object_rel_path 'ActiveBackup_2023-01-31_231917/system-root.img', uuid 'system-root.img', file size '2549940224', resume_rel_path '', resume_postfix: '', base_version_id: '33', ref_rel_path: ''
Jan 31 23:19:44 +0100 [INFO] disk-writer-helper.cpp:449(24192,140522448197376) Disk Writer open file over
Jan 31 23:19:44 +0100 [INFO] disk-writer-helper.cpp:452(24192,140522448197376) Disk Writer open file, base_version_object: version_id(): '33', object_uuid(): 'system-root.img', backup_context_base_version: '33', current_object_uuid: 'system-root.img'
Jan 31 23:19:50 +0100 [INFO] disk-writer-helper.cpp:551(24192,140522448197376) disk writer close file, file path object_rel_path: ActiveBackup_2023-01-31_231917/system-root.img, postfix: , file size: 2549940224, blSuspend[0]
Jan 31 23:19:50 +0100 [INFO] disk-writer-helper.cpp:554(24192,140522448197376) disk writer close file over
Jan 31 23:19:50 +0100 [INFO] disk-writer-helper.cpp:782(24192,140522448197376) stream checkpoint, root path: /volume1/ActiveBackupforBusiness/@ActiveBackup
Jan 31 23:19:54 +0100 [INFO] disk-writer-helper.cpp:785(24192,140522448197376) stream checkpoint over
Jan 31 23:19:54 +0100 [INFO] backup-workers.cpp:767(24192,140522448197376) [DEDUP] open m_disk_writer_helper
Jan 31 23:19:54 +0100 [INFO] disk-writer-helper.cpp:438(24192,140522448197376) Disk Writer open file object_rel_path 'ActiveBackup_2023-01-31_231917/synorbd_2.img', uuid 'synorbd_2.img', file size '251122745344', resume_rel_path '', resume_postfix: '', base_version_id: '33', ref_rel_path: ''
Jan 31 23:19:54 +0100 [INFO] disk-writer-helper.cpp:449(24192,140522448197376) Disk Writer open file over
Jan 31 23:19:54 +0100 [INFO] disk-writer-helper.cpp:452(24192,140522448197376) Disk Writer open file, base_version_object: version_id(): '33', object_uuid(): 'synorbd_2.img', backup_context_base_version: '33', current_object_uuid: 'synorbd_2.img'
Jan 31 23:20:09 +0100 [INFO] disk-writer-helper.cpp:551(24192,140522448197376) disk writer close file, file path object_rel_path: ActiveBackup_2023-01-31_231917/synorbd_2.img, postfix: , file size: 251122745344, blSuspend[0]
Jan 31 23:20:09 +0100 [INFO] disk-writer-helper.cpp:554(24192,140522448197376) disk writer close file over
Jan 31 23:20:10 +0100 [INFO] disk-writer-helper.cpp:782(24192,140522448197376) stream checkpoint, root path: /volume1/ActiveBackupforBusiness/@ActiveBackup
Jan 31 23:20:14 +0100 [INFO] disk-writer-helper.cpp:785(24192,140522448197376) stream checkpoint over
Jan 31 23:20:14 +0100 [INFO] backup-workers.cpp:767(24192,140522448197376) [DEDUP] open m_disk_writer_helper
Jan 31 23:20:14 +0100 [INFO] disk-writer-helper.cpp:438(24192,140522448197376) Disk Writer open file object_rel_path 'ActiveBackup_2023-01-31_231917/synorbd_1.img', uuid 'synorbd_1.img', file size '11992474714112', resume_rel_path '', resume_postfix: '', base_version_id: '33', ref_rel_path: ''
Jan 31 23:20:14 +0100 [INFO] disk-writer-helper.cpp:449(24192,140522448197376) Disk Writer open file over
Jan 31 23:20:14 +0100 [INFO] disk-writer-helper.cpp:452(24192,140522448197376) Disk Writer open file, base_version_object: version_id(): '33', object_uuid(): 'synorbd_1.img', backup_context_base_version: '33', current_object_uuid: 'synorbd_1.img'
Jan 31 23:21:53 +0100 [INFO] disk-writer-helper.cpp:551(24192,140522448197376) disk writer close file, file path object_rel_path: ActiveBackup_2023-01-31_231917/synorbd_1.img, postfix: , file size: 11992474714112, blSuspend[0]
Jan 31 23:21:53 +0100 [INFO] disk-writer-helper.cpp:554(24192,140522448197376) disk writer close file over
Jan 31 23:21:53 +0100 [INFO] disk-writer-helper.cpp:782(24192,140522448197376) stream checkpoint, root path: /volume1/ActiveBackupforBusiness/@ActiveBackup
Jan 31 23:21:53 +0100 [INFO] backup-workers.cpp:270(24192,140522439804672) BackupReadChannelWorker: stop, running task id 60
Jan 31 23:21:53 +0100 [INFO] backup-workers.cpp:535(24192,140522456590080) BackupDecompressWorker: stop, running task id 60
Jan 31 23:21:56 +0100 [INFO] disk-writer-helper.cpp:785(24192,140522448197376) stream checkpoint over
Jan 31 23:21:56 +0100 [INFO] backup-workers.cpp:741(24192,140522448197376) BackupWriteFileWorker: stop, running task id 60
Jan 31 23:21:57 +0100 [INFO] backup-workers.cpp:547(24192,140522469185280) delete m_disk_writer_helper
Jan 31 23:21:57 +0100 [INFO] backup-handler.cpp:59(24192,140522470237952) In handler '13BackupHandler' with action 'backup'.
Jan 31 23:21:57 +0100 [INFO] backup-handler.cpp:60(24192,140522470237952)    request is {"action": "backup", "agent": {"version": {"build": "12420", "major": 2, "mini": 2, "minor": 4}}, "ds_id": "26340e4b-0f8a-4473-af1d-337c6ad8d36c", "result_id": 653, "running_task_id": 60, "status": "complete", "subaction": "check_complete", "token": "6d081966267b5211f150fafa5589e86b"}
Jan 31 23:21:59 +0100 [WARNING] stream.cpp:779(24192,140522469185280) Channel: -2
Jan 31 23:21:59 +0100 [ERROR] stream.cpp:1823(24192,140522469185280) Error stack:
Jan 31 23:21:59 +0100 [ERROR] sync-task.cpp:144(24192,140522469185280) Failed to write message header. (code: -2)
Jan 31 23:21:59 +0100 [INFO] running-task-monitor.cpp:1178(24191,140522068899584) RunningTaskMonitor:: get Running task 60 not in map
Jan 31 23:22:00 +0100 [INFO] service-control.cpp:694(24191,140522428274432) ServiceRemoveJobByJobId: 2
Jan 31 23:22:00 +0100 [INFO] running-task-monitor.cpp:2163(24191,140522428274432) === Transfer Performance ===
Jan 31 23:22:00 +0100 [INFO] running-task-monitor.cpp:2164(24191,140522428274432)    duration_ns 301000000000.000000
Jan 31 23:22:00 +0100 [INFO] running-task-monitor.cpp:2165(24191,140522428274432)    transfer_duration_ns 284873192018.000000
Jan 31 23:22:00 +0100 [INFO] running-task-monitor.cpp:2166(24191,140522428274432)    snapshot_ns 16126807982.000000
Jan 31 23:22:00 +0100 [INFO] running-task-monitor.cpp:2167(24191,140522428274432)    read_disk_ns 5128307852.000000
Jan 31 23:22:00 +0100 [INFO] running-task-monitor.cpp:2168(24191,140522428274432)    send_ns 26165996023.000000
Jan 31 23:22:00 +0100 [INFO] running-task-monitor.cpp:2169(24191,140522428274432)    dedup_ns 16449439000.000000
Jan 31 23:22:00 +0100 [INFO] running-task-monitor.cpp:2170(24191,140522428274432)    write_ns 3782962000.000000
Feb 01 00:00:04 +0100 [INFO] miss-schedule-handler.cpp:93(24191,140522495416064) MissScheduleNotifyHandler Start

 

[Zottelhias]

In dem oben geposteten Auszug sind zwei Zeilen herforgehoben. Die sind mir aufgefallen. Das Problem an dem Ganzen ist nun, Zeile 30 kann es nicht sein. Denn laut Protokoll von ABFB wurde das Backup erst um 23:22:00 fertig - siehe folgenden Export des ABFB-Protokolls:

Protokolltyp,Protokollbeschreibung,Protokollzeit
Informationen,Geräteinformationen werden abgerufen.,2023-01-31 23:16:58
Informationen,Hochladen von Geräteinformationen wird gestartet.,2023-01-31 23:17:07
Informationen,Geräteinformationen erfolgreich geladen.,2023-01-31 23:17:08
Informationen,Lesen und Hochladen des Volume-Inhalts von / wird gestartet. [CBT],2023-01-31 23:17:08
Informationen,Lesen und Hochladen des Volume-Inhalts von /volume2 wird gestartet. [CBT],2023-01-31 23:17:13
Informationen,Lesen und Hochladen des Volume-Inhalts von /volume1 wird gestartet. [CBT],2023-01-31 23:17:24
Informationen,Erstellen von Schnappschuss für /volume2 wird gestartet.,2023-01-31 23:19:11
Informationen,Schnappschuss für /volume2 erfolgreich erstellt.,2023-01-31 23:19:12
Informationen,Erstellen von Schnappschuss für /volume1 wird gestartet.,2023-01-31 23:19:12
Informationen,Schnappschuss für /volume1 erfolgreich erstellt.,2023-01-31 23:19:18
Informationen,Erstellen von Schnappschuss für / wird gestartet.,2023-01-31 23:19:18
Informationen,Schnappschuss für / erfolgreich erstellt.,2023-01-31 23:19:18
Informationen,Volume-Inhalt von / erfolgreich gelesen und hochgeladen.,2023-01-31 23:19:36
Informationen,Volume-Inhalt von /volume2 erfolgreich gelesen und hochgeladen.,2023-01-31 23:19:56
Informationen,Volume-Inhalt von /volume1 erfolgreich gelesen und hochgeladen.,2023-01-31 23:21:39
Informationen,"Die durchschnittliche Sicherungsgeschwindigkeit beträgt 3.00 MB/s. Die Auslastung einzelner Komponenten wird unten angezeigt: Schnappschuss-Ausführung [5.36%], Lesen von Quell-Datenträger [1.80%], Übertragung von Quelldaten [9.19%], Datendeduplizierung [5.77%] und Schreiben in Datei [1.33%].",2023-01-31 23:22:00
Informationen,Die Sicherungsaufgabe NAS02_Backup wurde abgeschlossen.,2023-01-31 23:22:00

Das bedeutet ja nun, das ich nicht wie angenommen nach "Erfolgreich", "Successful" oder "Successfully" suchen sollte, sondern nach bestimmten Inhalten aus der folgenden Zeile:

Jan 31 23:21:57 +0100 [INFO] backup-handler.cpp:60(24192,140522470237952)    request is {"action": "backup", "agent": {"version": {"build": "12420", "major": 2, "mini": 2, "minor": 4}}, "ds_id": "26340e4b-0f8a-4473-af1d-337c6ad8d36c", "result_id": 653, "running_task_id": 60, "status": "complete", "subaction": "check_complete", "token": "6d081966267b5211f150fafa5589e86b"}

Würdet ihr das anhand des Logs auch so sehen, dass ich das gegen folgendes abgleichen sollte:
Datum vom aktuellen Tag in verkürtzter schreibweise (bspw. Jan 31)
request is
"action": "backup"
"status": "complete"
"subaction": "check_complete"

Als bedingung müsste das dann Bedeuten nur wenn alle vier Werte erfolgreich abgeglichen wurden, dann darf das NAS sich abschalten. Sprich es muss eine logische UND-Verknüpfung sein.

 

[Tommes]

In der Theorie klingt das ja schon mal nach einem Plan. Kannst du sagen, ob die running_task_id gleich der ID des Aufgabenplaners ist? Falls ja, könntest du hier die Brücke zurück schlagen um zusätzlich mittels der Pid zu prüfen, ob der Prozess beendet wurde. Sicherlich kannst du auch auf anderen Wegen an die Pid gelangen, falls du diesen Schritt überhaupt in Erwägung ziehst.

 

[Zottelhias]

@Tommes
Nun ja, Grundsätzlich schlage ich keine Idee aus. Die Frage ist, wo finde ich die ID vom Aufgabenplaner. Wenn du das schon weist, brauch ich nicht danach suchen. Daher meine bitte an dich, ums kurz zu halten: Kannst du das posten wie ich an die Pid gelange?

 

[Tommes]

…ums kurz zu halten…

*klick*

 

[Zottelhias]

@Tommes
Wenn ich dein Script in den Taskplaner mit einfüge und als Task-Nummer 60 einfüge und den Task ausführen lasse, sollte dort dann etwas geschehen?
Ich hätte nun erwartet das mich eine Meldung ereilt, dass die Aufgabe entweder nicht ausgeführt wird, oder das die Aufgabe mit der pid ... ausgefürht wird

Nebenbei sehe ich noch ein weiteres Problem mit dem date Befehl.
Ziel ist es das den Monat in kurzform (Jan) zu extrahieren.
Wenn ich

date --help

eingebe, bekomme ich die folgende Liste von Optionen:

Usage: date [OPTION]... [+FORMAT]
  or:  date [-u|--utc|--universal] [MMDDhhmm[[CC]YY][.ss]]
Display the current time in the given FORMAT, or set the system date.

Mandatory arguments to long options are mandatory for short options too.
  -d, --date=STRING          display time described by STRING, not 'now'
      --debug                annotate the parsed date,
                              and warn about questionable usage to stderr
  -f, --file=DATEFILE        like --date; once for each line of DATEFILE
  -I[FMT], --iso-8601[=FMT]  output date/time in ISO 8601 format.
                               FMT='date' for date only (the default),
                               'hours', 'minutes', 'seconds', or 'ns'
                               for date and time to the indicated precision.
                               Example: 2006-08-14T02:34:56-06:00
  -R, --rfc-email            output date and time in RFC 5322 format.
                               Example: Mon, 14 Aug 2006 02:34:56 -0600
      --rfc-3339=FMT         output date/time in RFC 3339 format.
                               FMT='date', 'seconds', or 'ns'
                               for date and time to the indicated precision.
                               Example: 2006-08-14 02:34:56-06:00
  -r, --reference=FILE       display the last modification time of FILE
  -s, --set=STRING           set time described by STRING
  -u, --utc, --universal     print or set Coordinated Universal Time (UTC)
      --help     display this help and exit
      --version  output version information and exit

FORMAT controls the output.  Interpreted sequences are:

  %%   a literal %
  %a   locale's abbreviated weekday name (e.g., Sun)
  %A   locale's full weekday name (e.g., Sunday)
  %b   locale's abbreviated month name (e.g., Jan)
  %B   locale's full month name (e.g., January)
  %c   locale's date and time (e.g., Thu Mar  3 23:05:25 2005)
  %C   century; like %Y, except omit last two digits (e.g., 20)
  %d   day of month (e.g., 01)
  %D   date; same as %m/%d/%y
  %e   day of month, space padded; same as %_d
  %F   full date; same as %Y-%m-%d
  %g   last two digits of year of ISO week number (see %G)
  %G   year of ISO week number (see %V); normally useful only with %V
  %h   same as %b
  %H   hour (00..23)
  %I   hour (01..12)
  %j   day of year (001..366)
  %k   hour, space padded ( 0..23); same as %_H
  %l   hour, space padded ( 1..12); same as %_I
  %m   month (01..12)
  %M   minute (00..59)
  %n   a newline
  %N   nanoseconds (000000000..999999999)
  %p   locale's equivalent of either AM or PM; blank if not known
  %P   like %p, but lower case
  %q   quarter of year (1..4)
  %r   locale's 12-hour clock time (e.g., 11:11:04 PM)
  %R   24-hour hour and minute; same as %H:%M
  %s   seconds since 1970-01-01 00:00:00 UTC
  %S   second (00..60)
  %t   a tab
  %T   time; same as %H:%M:%S
  %u   day of week (1..7); 1 is Monday
  %U   week number of year, with Sunday as first day of week (00..53)
  %V   ISO week number, with Monday as first day of week (01..53)
  %w   day of week (0..6); 0 is Sunday
  %W   week number of year, with Monday as first day of week (00..53)
  %x   locale's date representation (e.g., 12/31/99)
  %X   locale's time representation (e.g., 23:13:48)
  %y   last two digits of year (00..99)
  %Y   year
  %z   +hhmm numeric time zone (e.g., -0400)
  %:z  +hh:mm numeric time zone (e.g., -04:00)
  %::z  +hh:mm:ss numeric time zone (e.g., -04:00:00)
  %:::z  numeric time zone with : to necessary precision (e.g., -04, +05:30)
  %Z   alphabetic time zone abbreviation (e.g., EDT)

By default, date pads numeric fields with zeroes.
The following optional flags may follow '%':

  -  (hyphen) do not pad the field
  _  (underscore) pad with spaces
  0  (zero) pad with zeros
  ^  use upper case if possible
  #  use opposite case if possible

After any flags comes an optional field width, as a decimal number;
then an optional modifier, which is either
E to use the locale's alternate representations if available, or
O to use the locale's alternate numeric symbols if available.

Examples:
Convert seconds since the epoch (1970-01-01 UTC) to a date
  $ date --date='@2147483647'

Show the time on the west coast of the US (use tzselect(1) to find TZ)
  $ TZ='America/Los_Angeles' date

Show the local time for 9AM next Friday on the west coast of the US
  $ date --date='TZ="America/Los_Angeles" 09:00 next Fri'

GNU coreutils online help: <https://www.gnu.org/software/coreutils/>
Full documentation at: <https://www.gnu.org/software/coreutils/date>
or available locally via: info '(coreutils) date invocation'

Versuche ich nun

date %b
date: invalid date ‘%b’

date --utc%b
date: unrecognized option '--utc%b'
Try 'date --help' for more information.

date --utc %b
date: invalid date ‘%b’

date +b
b

date --utc+b
date: unrecognized option '--utc+b'
Try 'date --help' for more information.

date --utc
Wed Feb  1 19:53:43 UTC 2023

date --utc
Wed Feb  1 19:53:43 UTC 2023

 date -I
2023-02-01

erzeiehlt das keine Wirkung.
Hat da jemand Rat zu oder habe ich da was falsch gelesen, dass es bei mir nicht geht?

 

[luddi]

Probier doch mal folgende Syntax:

date +%b

Und wenn du es einer Variablen zuweisen möchtest dann eben so:

var=$(date '+%b')

 

[Zottelhias]

@luddi
Danke für den Hinweis. Ich weiß, mekkern sollte man nicht aber dieses + Zeichen hätten die auch, wenn Sie sich schon die mühe machen Prozent-Zeichen mit anzugeben vor das Prozent-Zeichen setzen können. Anstatt nur oben vor dem Wort Format einmal zu erwähnen. Sollte nicht so schwer sein. Ich übernehme auch die Aufgabe.

 

[Zottelhias]

So langsam finde ich das ziemlich komisch:

varCurentDate=date

$varCurentDate
Thu Feb  2 06:56:04 CET 2023

varCurentMonth=$varCurentDate +%b
-sh: +%b: command not found

varCurentMonth=$(varCurentDate +%b)
-sh: varCurentDate: command not found

varCurentMonth=$(varCurentDate '+%b')
-sh: varCurentDate: command not found

varCurentMonth=$varCurentDate '+%b'
-sh: +%b: command not found

$varCurentDate
Thu Feb  2 06:59:33 CET 2023

varCurentMonth=date +%b
-sh: +%b: command not found

varCurentMonth=(date +%b)

$varCurentMonth
-sh: varCurentMonth: command not found

$varCurentMonth=(date +%b)

$varCurentMonth
-sh: varCurentMonth: command not found

varCurentMonth=$(date +%b)

varCurentMonth
-sh: varCurentMonth: command not found

varCurentMonth=$(date '+%b')

$varCurentMonth
-sh: varCurentMonth: command not found

$varCurentMonth=date +%b

varCurentMonth=date [+%b]
-sh: [+%b]: command not found

varCurentMonth=[date +%b]
-sh: +%b]: command not found

varCurentMonth=(date '+%b')

$varCurentMonth
-sh: varCurentMonth: command not found

varCurentMonth=($varCurentDate +%b)

$varCurentMonth
Thu Feb  2 07:14:44 CET 2023

varCurentMonth=($varCurentDate '+%b')

$varCurentMonth
Thu Feb  2 07:15:34 CET 2023

Was auch immer ich falsch mache... sagt es mir, bitte.