Protokolierte Zeit im Joblog seltsam

[Robi]

Hi *all
leider ist unser Sicherungsthema noch nicht erledigt

Ein Joblog, vom BRMS erzeugt, hat folgende Protokollierung, die ich nicht verstehe. (nur Auszüge)
Es geht um den Zeitlichen ablauf!

CPI1125    Information             00   01.08.16  22:06:00,223289  QWTPCRJA     QSYS        0110     *EXT
                                     Nachricht . . . :   Job 939690/XXX/MONTHLY übergeben.               

...

...


 CPI6705    Information             00   02.08.16  07:37:35,580185  Q1AXCMD2     QBRM        *STMT    Q1ACSLIB    
                                      Ausgangsmodul . . . . . . . :   Q1AXCMD                                     
                                      Ausgangsprozedur  . . . . . :   ReceiveMessages                             
                                      Anweisung . . . . . . . . . :   70                                          
                                      Zielmodul . . . . . . . . . :   Q1ACSLIB                                    
                                      Zielprozedur  . . . . . . . :   Q1ACSLIB                                    
  5770SS1 V7R1M0 100423                           Jobprotokoll                        S4405619 02.08.16 08:53:48  
   Jobname  . . . . . . . . . . :   MONTHLY         Benutzer  . . . . :   UBL          Nummer . . . . . . . . . . 
   Jobbeschreibung  . . . . . . :   QDFTJOBD        Bibliothek  . . . :   QGPL                                    
 NACHR-ID   ART                     BEW  DATUM     ZEIT             VON PGM      BIBLIOTHEK  INST     AN PGM      
                                      Anweisung . . . . . . . . . :   1535                                        
                                      Nachricht . . . :   4543 Blöcke für Sequenz 579, Datenträger MS0701, auf    

                                       Einheit TAPMLB01 verarbeitet.                                                              
                                     Ursache  . . . . :  4543 Blöcke wurden für Dateikennsatz ZV_FRAUKE, Sequenz                  
                                       579 für Datenträger MS0701, geladen in Einheit TAPMLB01, verarbeitet. Die                  
                                       maximale Blockgröße beträgt 262144. Die Banddatei wurde um 02.08.16 07:37:16               
                                       geöffnet und um 02.08.16 07:37:20 geschlossen. Die Datei war insgesamt 4                   
                                       Sekunden geöffnet. Wenn es sich bei der Einheit um ein Bandarchiv handelt,                 
                                       ist die Kassette MS0701 und die Ressource TAP01.                                           
CPC3701    Beendigung              00   02.08.16  07:37:35,587682  Q1AXCMD2     QBRM        *STMT    Q1ACSLIB    QBRM        *STMT
                                     Ausgangsmodul . . . . . . . :   Q1AXCMD                                                      
                                     Ausgangsprozedur  . . . . . :   ReceiveMessages                                              
                                     Anweisung . . . . . . . . . :   70                                                           
                                     Zielmodul . . . . . . . . . :   Q1ACSLIB                                                     
                                     Zielprozedur  . . . . . . . :   Q1ACSLIB                                                     
                                     Anweisung . . . . . . . . . :   1535                                                         
                                     Nachricht . . . :   11 Objekt(e) aus Bibliothek ZV_FRAUKE gesichert.                         
                                     Ursache. . . . . : -- 11 Objekte wurden gesichert. -- 0 Spool-Dateien wurden                 
                                       gesichert. Die Daten wurden auf den Datenträgern MS0701  Folgenummer 579                   
                                       am/um 01.08.16 23:29:28 gesichert. Der Sicherungsvorgang endete beim                       
                                       Datenträger MS0701. Wurde UPDHST(*YES) angegeben, wurde das
                                       Sichern/Zurückspeichern-Protokoll aktualisiert, falls nicht in den vorher    
                                       aufgelisteten Nachrichten etwas anderes angegeben wurde.                     
CPC3707    Beendigung              00   02.08.16  07:37:35,594263  Q1AXCMD2     QBRM        *STMT    Q1ACSLIB    QBRM
                                     Ausgangsmodul . . . . . . . :   Q1AXCMD                                        
                                     Ausgangsprozedur  . . . . . :   ReceiveMessages                                
                                     Anweisung . . . . . . . . . :   70                                             
                                     Zielmodul . . . . . . . . . :   Q1ACSLIB                                       
                                     Zielprozedur  . . . . . . . :   Q1ACSLIB                                       
                                     Anweisung . . . . . . . . . :   1535                                           
                                     Nachricht . . . :   427 Bibliothek(en) am/um 01.08.16 23:29:28 gesichert.      
                                     Ursache. . . . . :  Der Sicherungsvorgang endete auf Datenträger MS0701.       
BRM1058    Information             00   02.08.16  07:37:42,038130  Q1ACALG      QBRM        *STMT    Q1ACALG     QBRM
                                     Ausgangsmodul . . . . . . . :   Q1ACALG

Fehlt hier ein PTF oder ist das Normal?

Danke
Robi

[Fuerchau]

Die obere Uhrzeit ist die Zeit der Ankunft des Joblog-Eintrages, die Uhrzeit innerhalb der Nachricht wird von der Anwendung selber eingestellt.
Da fragt man sich halt nur, was das Programm ca. 8 Stunden so getrieben hat bevor es die Nachricht ins Joblog stellte.

[Robi]

Ja, aber die Einträge sind völlig durcheinander


gepostet habe ich Seite 1 (ganz oben) und Seite 295(ab ...)

Auf Seite 100, also viel früher, finde ich,

NACHR-ID   ART                     BEW  DATUM     ZEIT             VON PGM      BIBLIOTHEK  INST     AN PGM      BIBLIOTHEK
                                     Anweisung . . . . . . . . . :   1535                                                  
                                     Nachricht . . . :   19177 Blöcke für Sequenz 187, Datenträger MS0701, auf             
                                       Einheit TAPMLB01 verarbeitet.                                                       
                                     Ursache  . . . . :  19177 Blöcke wurden für Dateikennsatz BECKEROT, Sequenz           
                                       187 für Datenträger MS0701, geladen in Einheit TAPMLB01, verarbeitet. Die           
                                       maximale Blockgröße beträgt 262144. Die Banddatei wurde um 02.08.16 04:08:51        
                                       geöffnet und um 02.08.16 04:09:10 geschlossen. Die Datei war insgesamt 20           
                                       Sekunden geöffnet. Wenn es sich bei der Einheit um ein Bandarchiv handelt,          
                                       ist die Kassette MS0701 und die Ressource TAP01.                                    
CPC3701    Beendigung              00   02.08.16  07:37:28,081898  Q1AXCMD2     QBRM        *STMT    Q1ACSLIB    QBRM      
                                     Ausgangsmodul . . . . . . . :   Q1AXCMD                                               
                                     Ausgangsprozedur  . . . . . :   ReceiveMessages                                       
                                     Anweisung . . . . . . . . . :   70                                                    
                                     Zielmodul . . . . . . . . . :   Q1ACSLIB

die Protokollierung springt also mal vom 2.8. dann vom 1.8. dann wieder vom 2.8.

ist das echt ok?

[Pikachu]

427 Bibliotheken gesichert ...

Da fragt man sich halt nur, was das Programm ca. 8 Stunden so getrieben hat bevor es die Nachricht ins Joblog stellte.

[Fuerchau]

Ich kann keine Datumsprünge entdecken.
Auf deiner Seite 100 ist die nächste Meldung doch vom 02.08.16 07:37:28,081898.
Wo ist dein Problem?
Noch mal: die Zeile, die die Nachrichten-ID enthält ist die Zeit, wann diese ins Joblog geschrieben wurde.
Die Zeit innerhalb des Nachrichtentextes stellt das Programm zur Verfügung.
Ansonsten kann ich halt nur vermuten, dass die Zeit innerhalb der Nachricht die Startzeit ist und die Zeit im Joblog dann die Endezeit.

Das erklärt natürlich Pikachus Antwort:
427 Bibliothek(en) am/um 01.08.16 23:29:28 gesichert
Gesendet: CPC3707 Beendigung 00 02.08.16 07:37:35,594263
Damit wird wohl ausgesagt, dass um 23:29:28 die Sicherung tatsächlich startet und um 07:37:35 am nächsten Tag fertig ist.