Topic
  • 7 replies
  • Latest Post - ‏2015-08-04T09:48:00Z by Enrico_Joedecke
KarinMoitzfeld
KarinMoitzfeld
8 Posts

Pinned topic wrong date shown in samlog

‏2015-07-31T09:28:14Z | samlog

Hi all,

I don't know why the Output of samlog Shows the wrong date. Same wrong Dates are shown with rpttr -odtic .... I'm working on an oslevel -s 7100-03-04-1441

If I type date, the correct time is shown. Why is the wrong date logged? Is there any wrong config for rsct or trace logging?

samlog called at 2015-07-31 10:11:11 on zdom002 with options -t 1d
zdom002 0.00 IBM.RecoveryRM trace_summary, IBM.GblResRM trace_summary
---------------------------------------------------------------------
1922-11-10 07:51:38.318569 G(zdom002) T(  1) ____  ******************* Trace Started - Pid = 7143464 **********************
1922-11-10 07:51:38.535656 R(zdom002) T(  1) ____  ******************* Trace Started - Pid = 9109616 **********************
1922-11-10 07:51:38.808359 R(zdom002) T(809) _RCD CHARM::processMembership() Master daemon node name - zdom002, NodeNum = 1
1922-11-10 07:51:38.817326 R(zdom002) T(b0c) _RCD CHARM::verifyConfig Entered

best regards

Karin
 

  • Enrico_Joedecke
    Enrico_Joedecke
    121 Posts
    ACCEPTED ANSWER

    Re: wrong date shown in samlog

    ‏2015-08-03T14:52:24Z  

    Hello Karin, Ruediger,

    the output of 'rpttr' (samlog) depends on the time zone setting of the node, where the command is executed. If the '$TZ' value is not recognized, or set to a different time zone than the current, the command might report unexpected output (unexpected offset). A time difference of 1 hour might also be observed in case the trace starts in 'Winter-time', and 'rpttr' is run within 'Summer-time', or the other way around.

    The rpttr output shows a line after the header with the offset used for formatting, e.g.:

                                    *** Formatting traces using TZ=UTC+02:00 ***

    The displayed time zone offset can be forced using the following syntax/options for the 'rpttr' command:

         TZ=UTC-02:00 rpttr -o dtic -lk /var/ct/<domain>/log/mc/IBM.<RM>/<trace-file>

    UTC-02:00     as used in this example is the time zone 2 hours before/East of UTC, as it is currently in Germany (Summer time!)

     

    This does however not answer the question why the year 1922 is shown within rpttr output. For this I assume the nodes have an RSCT level of 3.2.0.x (x<6) installed. There is a known issue with trace formatting when using those RSCT levels.

     

    Let me finally comment on 'samdiag':

    samdiag time stamps (samdiag history) are always based on UTC. There is no offset calculation, the engine simply dumps its resource information from memory into a file. The 2 hours offset you are observing are the current 2 hours between German time, and UTC.

     

    regards,

    Enrico

  • Rüdiger Dahlke
    Rüdiger Dahlke
    121 Posts

    Re: wrong date shown in samlog

    ‏2015-08-03T07:20:36Z  

    Hello Karin,

    we have seen the same: different timestamps in trace, syslog and samdiag. I've opened a pmr last week: 41332,035,724. samdiag is allways 2 hours back, trace one hour.

    regards

    Ruediger

  • KarinMoitzfeld
    KarinMoitzfeld
    8 Posts

    Re: wrong date shown in samlog

    ‏2015-08-03T07:27:56Z  

    Hello Rüdiger,

     

    thank you for your answer. I'll open a pmr too. As you see in my Output, we are some years (1922)! ago.

     

    regards

    Karin

  • Enrico_Joedecke
    Enrico_Joedecke
    121 Posts

    Re: wrong date shown in samlog

    ‏2015-08-03T14:52:24Z  

    Hello Karin, Ruediger,

    the output of 'rpttr' (samlog) depends on the time zone setting of the node, where the command is executed. If the '$TZ' value is not recognized, or set to a different time zone than the current, the command might report unexpected output (unexpected offset). A time difference of 1 hour might also be observed in case the trace starts in 'Winter-time', and 'rpttr' is run within 'Summer-time', or the other way around.

    The rpttr output shows a line after the header with the offset used for formatting, e.g.:

                                    *** Formatting traces using TZ=UTC+02:00 ***

    The displayed time zone offset can be forced using the following syntax/options for the 'rpttr' command:

         TZ=UTC-02:00 rpttr -o dtic -lk /var/ct/<domain>/log/mc/IBM.<RM>/<trace-file>

    UTC-02:00     as used in this example is the time zone 2 hours before/East of UTC, as it is currently in Germany (Summer time!)

     

    This does however not answer the question why the year 1922 is shown within rpttr output. For this I assume the nodes have an RSCT level of 3.2.0.x (x<6) installed. There is a known issue with trace formatting when using those RSCT levels.

     

    Let me finally comment on 'samdiag':

    samdiag time stamps (samdiag history) are always based on UTC. There is no offset calculation, the engine simply dumps its resource information from memory into a file. The 2 hours offset you are observing are the current 2 hours between German time, and UTC.

     

    regards,

    Enrico

  • KarinMoitzfeld
    KarinMoitzfeld
    8 Posts

    Re: wrong date shown in samlog

    ‏2015-08-04T05:45:44Z  

    Hello Karin, Ruediger,

    the output of 'rpttr' (samlog) depends on the time zone setting of the node, where the command is executed. If the '$TZ' value is not recognized, or set to a different time zone than the current, the command might report unexpected output (unexpected offset). A time difference of 1 hour might also be observed in case the trace starts in 'Winter-time', and 'rpttr' is run within 'Summer-time', or the other way around.

    The rpttr output shows a line after the header with the offset used for formatting, e.g.:

                                    *** Formatting traces using TZ=UTC+02:00 ***

    The displayed time zone offset can be forced using the following syntax/options for the 'rpttr' command:

         TZ=UTC-02:00 rpttr -o dtic -lk /var/ct/<domain>/log/mc/IBM.<RM>/<trace-file>

    UTC-02:00     as used in this example is the time zone 2 hours before/East of UTC, as it is currently in Germany (Summer time!)

     

    This does however not answer the question why the year 1922 is shown within rpttr output. For this I assume the nodes have an RSCT level of 3.2.0.x (x<6) installed. There is a known issue with trace formatting when using those RSCT levels.

     

    Let me finally comment on 'samdiag':

    samdiag time stamps (samdiag history) are always based on UTC. There is no offset calculation, the engine simply dumps its resource information from memory into a file. The 2 hours offset you are observing are the current 2 hours between German time, and UTC.

     

    regards,

    Enrico

    Hello Enrico,

     

    thank you for these explanations.

    I have really a problem with rsct. This will be fixed with TSAMP 4.1.0.2 fixpack which is coming soon.

    But one more remark: Didn't they say that TSAMP 4.1 will be independend to rsct?

     

    regards

    Karin

  • Rüdiger Dahlke
    Rüdiger Dahlke
    121 Posts

    Re: wrong date shown in samlog

    ‏2015-08-04T05:49:09Z  

    Hello Karin, Ruediger,

    the output of 'rpttr' (samlog) depends on the time zone setting of the node, where the command is executed. If the '$TZ' value is not recognized, or set to a different time zone than the current, the command might report unexpected output (unexpected offset). A time difference of 1 hour might also be observed in case the trace starts in 'Winter-time', and 'rpttr' is run within 'Summer-time', or the other way around.

    The rpttr output shows a line after the header with the offset used for formatting, e.g.:

                                    *** Formatting traces using TZ=UTC+02:00 ***

    The displayed time zone offset can be forced using the following syntax/options for the 'rpttr' command:

         TZ=UTC-02:00 rpttr -o dtic -lk /var/ct/<domain>/log/mc/IBM.<RM>/<trace-file>

    UTC-02:00     as used in this example is the time zone 2 hours before/East of UTC, as it is currently in Germany (Summer time!)

     

    This does however not answer the question why the year 1922 is shown within rpttr output. For this I assume the nodes have an RSCT level of 3.2.0.x (x<6) installed. There is a known issue with trace formatting when using those RSCT levels.

     

    Let me finally comment on 'samdiag':

    samdiag time stamps (samdiag history) are always based on UTC. There is no offset calculation, the engine simply dumps its resource information from memory into a file. The 2 hours offset you are observing are the current 2 hours between German time, and UTC.

     

    regards,

    Enrico

    Hello Enrico,

    I've tested this on one of our Test Servers. Here is what I see in the header of the trace file:

    Filename: trace.1.sp
            Program Name: /usr/sbin/rsct/bin/IBM.RecoveryRMd
            Properties: Little Endian, 32-bit mode
            Platform: Linux/Intel
            FileVersion: 5
            Node Number: 1
            Process Id: 62722
            Machine Id: 0x00000000
            Node ID:    0xdba396a225143762
            Trace Library Build Level: rliss009a
                                    *** Formatting traces using TZ=UTC+02:00 ***

     

    but the time shown in the trace nevertheless are actual:

    08/04/15 07:44:25.245956 T(3990555504) _RCD         CHARMControlRcp::getAttributeValues.
     08/04/15 07:44:25.249727 T(3990555504) _RCD         CHARMControlRcp::getAttributeValues.
     08/04/15 07:44:25.252806 T(3990555504) _RCD         CHARMControlRcp::getAttributeValues.

     07:44:... was the time I issued this command: rpttr -o dtic trace.1.sp

    But this is version V 4.1.0.1

    Regards

    Ruediger

     

     

     

  • Enrico_Joedecke
    Enrico_Joedecke
    121 Posts

    Re: wrong date shown in samlog

    ‏2015-08-04T08:18:28Z  

    Hello Enrico,

     

    thank you for these explanations.

    I have really a problem with rsct. This will be fixed with TSAMP 4.1.0.2 fixpack which is coming soon.

    But one more remark: Didn't they say that TSAMP 4.1 will be independend to rsct?

     

    regards

    Karin

    Hello Karin,

    not sure, what is meant by 'independent to rsct' ...

    SA MP always requires RSCT as cluster infrastructure. On AIX, where the RSCT is also part of the OS, the RSCT level might be higher than the level packaged with SA MP, and certain SA MP levels might tolerate even a lower RSCT level than packaged.

    For RSCT 3.2.0.x this is unfortunately not always the case:

    - SA MP 4.1.0.0 was shipped with RSCT 3.1.5, and does not work reliably with RSCT 3.2.0.0 (see also APAR IV71771), however efixes are available

    - SA MP 4.1.0.1 requires at least the packaged RSCT 3.2.0.4, due to issues we discovered during test with RSCT 3.2.0.x (x<4).

     

    So - YES - usually the installed RSCT level might be higher than the packaged RSCT level for SA MP to work, but there are some exceptions as mentioned above.

     

    regards,
    Enrico

  • Enrico_Joedecke
    Enrico_Joedecke
    121 Posts

    Re: wrong date shown in samlog

    ‏2015-08-04T09:48:00Z  

    Hello Enrico,

    I've tested this on one of our Test Servers. Here is what I see in the header of the trace file:

    Filename: trace.1.sp
            Program Name: /usr/sbin/rsct/bin/IBM.RecoveryRMd
            Properties: Little Endian, 32-bit mode
            Platform: Linux/Intel
            FileVersion: 5
            Node Number: 1
            Process Id: 62722
            Machine Id: 0x00000000
            Node ID:    0xdba396a225143762
            Trace Library Build Level: rliss009a
                                    *** Formatting traces using TZ=UTC+02:00 ***

     

    but the time shown in the trace nevertheless are actual:

    08/04/15 07:44:25.245956 T(3990555504) _RCD         CHARMControlRcp::getAttributeValues.
     08/04/15 07:44:25.249727 T(3990555504) _RCD         CHARMControlRcp::getAttributeValues.
     08/04/15 07:44:25.252806 T(3990555504) _RCD         CHARMControlRcp::getAttributeValues.

     07:44:... was the time I issued this command: rpttr -o dtic trace.1.sp

    But this is version V 4.1.0.1

    Regards

    Ruediger

     

     

     

    Hello Ruediger,

    am I right that the 'issue' you observe is that the trace header shows 'UTC+02:00', while I mentioned to use 'UTC-02:00' ?

    If so, then I think the issue is within the output of the trace header file (within rpttr command).

    The UNIX TZ naming is not very intuitive - e.g. in Germany it is currently 2 hours later then UTC, which would lead to a calculated time/hour value of 'UTC+02:00', but the TZ setting in UNIX is the opposite, it basically has a positive offset for all timezones that are in the 'west', and a negative for 'east' of UTC (see also 'man timezone').

     

    Hope that explains the observed behavior.

    regards,

    Enrico