Viewing Cloverleaf 6.0 process logs

Clovertech Forums Read Only Archives Cloverleaf Cloverleaf Viewing Cloverleaf 6.0 process logs

  • Creator
    Topic
  • #54046
    Jennifer Hardesty
    Participant

      I know a lot of facilities are not dependent on the process logs for troubleshooting or auditing.  I’m happy for those of you who have made peace using SMAT files and almost empty process logs as your method.

      However, our facility does use process logs.  In fact, we would consider it a show stopper if they stopped working altogether.

      Anyway, it turns out in our upgrade from CL5.7 to CL6.0 in our test environment that the first 59 characters of every line in the process logs are a string populated by Cloverleaf and there appears to be no way to turn this off.  This makes seeing what we populate the log files with very difficult.

      See below:

      Code:

      [tcl :out :INFO/0:epic_a_out_961701:–/–/—- –:–:–]
      [tcl :out :INFO/0:epic_a_out_961701:–/–/—- –:–:–] **** epic_a_out_961701/mmc_save_ob_msg – msg 11666 SENT at 2014-02-12 08:48:00
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00]    MSH|^~&|PBMC|||EPICT|20140212084700||ADT^A03|11666|P|2.2
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00]    EVN|A03|20140212084700.0000-0500
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00]    PID|1||~M4008020^^^^PBMC||PRE^INSCU||19401001084700.0000-0500|F||W|409 OLD COUNTY RD^^R
      OCKLAND^ME^04841||(207)555-1212|||W||M30000100104
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00]    PV1|1||IPBM|U|||^STAFF MEMBER^MISSING NAME^^^^MD^^^^^^PENBAYPROV|||SCU||||2|||NICCA^PACKARD^PENNY^^^^MD|||MCRA||||||||||||||||1|||PBM|||||20130719103800-0500|20140212084700-0500
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00]    
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00]
      [tcl :out :INFO/0:epic_a_out_961701:–/–/—- –:–:–] epic_a_out_961701/mmc_validate_reply – ACK RCVD at 2014-02-12 08:48:00
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00]    MSH|^~&||EPICT|PBMC||20140212084800||ACK|11666|P|2.2|||||
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00]    MSA|AR|11666|Incorrect Processing ID|||
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00]    
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00]
      [tcl :out :INFO/0:epic_a_out_961701:–/–/—- –:–:–] **** epic_a_out_961701/mmc_validate_reply : Three consecutive AR responses – Incorrect Pro
      cessing ID
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00] Message to Error Database
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00] Reply is:
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00] MSH|^~&||EPICT|PBMC||20140212084800||ACK|11666|P|2.2|||||^MMSA|AR|11666|Incorrect Process
      ing ID|||
      [tcl :out :INFO/0:epic_a_out_961701:–/–/—- –:–:–]
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00]
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00] Message is:
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00] MSH|^~&|PBMC|||EPICT|20140212084700||ADT^A03|11666|P|2.2^MEVN|A03|20140212084700.0000-050
      0^MPID|1||~M4008020^^^^PBMC||PRE^INSCU||19401001084700.0000-0500|F||W|409 OLD COUNTY RD^^ROCKLAND^ME^04841||(207)555-1212|||W||M30000100104^MPV1|1|
      |IPBM|U|||^STAFF MEMBER^MISSING NAME^^^^MD^^^^^^PENBAYPROV|||SCU||||2|||NICCA^PACKARD^PENNY^^^^MD|||MCRA||||||||||||||||1|||PBM|||||20130719103800
      -0500|20140212084700-0500
      [tcl :out :INFO/0:epic_a_out_961701:02/12/2014 08:48:00]
      [tcl :out :INFO/0:epic_a_in_961700:02/12/2014 08:48:00]
      [tcl :out :INFO/0:epic_a_in_961700:–/–/—- –:–:–] epic_a_in_961700/tps_hl7_raw_ack – msg rcvd at 2014-02-12 08:48:00
      [tcl :out :INFO/0:epic_a_in_961700:02/12/2014 08:48:00]    MSH|^~&|EPIC|REG_UPDATE|||20140212084755|1340|ADT^A28|17855|T|2.4|||||||||
      [tcl :out :INFO/0:epic_a_in_961700:02/12/2014 08:48:00]    EVN|A28|20140212084755|||^MOSELY^MANDA^M^^^^^MH^^^^^MMC||
      [tcl :out :INFO/0:epic_a_in_961700:02/12/2014 08:48:00]    PID|1||E2172155^^^MEPI^MEPI||HYBITDSC^TESTONE||19560811|M|||^^^^^USA^^^||||||||455-20-01
      22|||||||||||N
      [tcl :out :INFO/0:epic_a_in_961700:02/12/2014 08:48:00]    PD1|||MAINE MEDICAL CENTER^^11001|||||||||||||||
      [tcl :out :INFO/0:epic_a_in_961700:02/12/2014 08:48:00]    PV1|1|N|^^^^^^^^^^|||||||||||||||||||||||||||||||||||||||^^^^^^^^^^||||||||
      [tcl :out :INFO/0:epic_a_in_961700:02/12/2014 08:48:00]    PV2||||||||||||||||||||||N|||||||||||||||||||||||||||
      [tcl :out :INFO/0:epic_a_in_961700:02/12/2014 08:48:00]    AL1|1||^||||||

      Imagine if you are attempting to view the log file on an 80 character screen?  You would only see 20 characters before it would wrap around and disrupt the flow of the logfile.  If you can view it on a larger screen, good for you, but you still have to contend with 59 characters you don’t wish to see.  (We normally view using the less command in AIX using Reflections or ReflectionsX.)

      I dug around this site and didn’t see any postings about this change in the process logs.  So I wondered if it’s just us bothered by it or if there’s a solution we’re overlooking?  

      (BTW, one of our analysts actually does think this should be a show stopper, I think. 😉 )

      Thanks in advance for any advice.

    Viewing 11 reply threads
    • Author
      Replies
      • #79972
        Chris Williams
        Participant

          We’re not on 6.0 yet, but it looks a lot like you have the EO turned up, or you have some Tcl code generating all of those lines.

          I have a couple of band-aids for you:

          1. Change your Reflection settings. In the version we use: Setup > Display > Screen > Columns. Set the number of columns that works for you. You may need to adjust the font to improve readability. (I happen to use 196 columns).

          2. Use “colrm [startcol [endcol]]”  in conjunction with “less” to remove the columns you don’t want to see. “colrm” reads from stdin and writes to stdout so you can use it like a filter.

          Code:

          cat logFileName | colrm 1 59 | less

          Cheers.

        • #79973
          Terry Kellum
          Participant

            Try this as a quick hack.

            Code:



            sed ‘s/^.{59}//’ Filename  | less

            This uses sed to substitute 59 of any character at the beginning of the line with nothing, then pipes the output to less.  If you want, you could incorporate this into a script outputting the file with a different file extension.

          • #79974
            Terry Kellum
            Participant

              That’s a winner Chris!!!!

            • #79975
              Chris Williams
              Participant

                I forgot to mention in my suggestion for changing the Reflection settings that you will also need to tell your AIX session what screen width you are using. Running in Linux we have a script that contains:

                Code:

                export COLUMNS=196
                export LINES=72

              • #79976
                Russ Ross
                Participant

                  I concluded the extra information in the Cloverleaf 6.0 process log files is an enhancement from our previous Cloverleaf 5.6 log files, but then my xterms are about 200 characters wide.

                  I know I’ve been asking for years to have each and every entry in the log file time stamped.

                  This can really help with trouble shooting when trying to determine what happened percisely when.

                  Interesting to see how one person’s dream is another person’s nightmare.

                  I would agree the log files aren’t backward freindly with an 80 character limitation.

                  Even without the extra log information, I would of considered that to be true so ouch on that 80 character restriction.

                  Russ Ross
                  RussRoss318@gmail.com

                • #79977
                  Jim Kosloskey
                  Participant

                    There has been a long standing request for the Engine to date/time stamp Log Entries to assist in debugging.

                    That has been deployed in 6.0.0 and also includes the thread name.

                    Perhaps requesting a EO Config option or something like that to suppress date/time stamp in a future release may give relief to those with terminal challenges.

                    Even though I have a laptop with a small screen I appreciate the date.time stamp.

                    In fact, I would think this would really be welcome if the log is primarily used for analysis because now there is no question as to when the events are logged.

                    email: jim.kosloskey@jim-kosloskey.com 29+ years Cloverleaf, 59 years IT - old fart.

                  • #79978
                    Rob Abbott
                    Keymaster

                      Hi all,

                      I hear you this and we will look at making the EO detail on Tcl echos optional in a future release.

                      Rob Abbott
                      Cloverleaf Emeritus

                    • #79979
                      Jim Kosloskey
                      Participant

                        Rob,

                        Also note that when a Tcl proc echos multiple lines to the log the date/time portion is not always filled in.

                        A line from Jennifer’s post:

                        [tcl :out :INFO/0:epic_a_out_961701:–/–/—- –:–:–] **** epic_a_out_961701/mmc_validate_reply : Three consecutive AR responses – Incorrect Pro

                        email: jim.kosloskey@jim-kosloskey.com 29+ years Cloverleaf, 59 years IT - old fart.

                      • #79980
                        David Barr
                        Participant

                          less -S logFileName

                          You can hit the left and right cursor keys to scroll left and right.

                          It’s too bad that the log file lines are so long.

                        • #79981
                          Jennifer Hardesty
                          Participant

                            Sorry for my slowness in getting back.

                            My original post was sort of an “all-inclusive” team grump regarding the change.  As we all know, every site and even every individual has their preferences.  We here at MMC have spent years tweaking the logs so they appear exactly the way we wish.  If you noted in my example, our part of the information already has the thread names as well as date/time stamps.  We have very detailed logs which include the messages, the ack/naks, tclprocs that process or supress them as well as the reasons why they are supressed.

                            I figure, if you wanted that kind of information in your logs, you should have put it there in the first place. 😉  I find that having it thrust on us now and in such an intrusive manner is rather inconsiderate and impolite.  One of our analysts almost considered it a “show-stopper”.  (I’m not kidding.  I talked her out of that.)

                            As you said, one person’s improvement is another person’s junk -er- nightmare -er- albatross.

                            We have upgraded our telnet services this week so we’re trying Xming and Kitty.  Now everyone is using the same product at least. So we’re not restricted to the small window.  And I have found a more appropriate way to strip the inconsistent number of starting characters out when looking at the logs:

                            cut

                          • #79982

                            We will be adding an option to turn off that extra logging in an upcoming release. An AR has been submitted.

                            That being said, it’s simple enough to use the system tools to clean up your output. I see that you already mentioned awk/sed, and cut, which is a great place to start.

                            -- Max Drown (Infor)

                          • #79983

                            Also, a quick note on process logging …

                            The slowest part of any computer system is disk I/O. It is orders of magnitude slower than the rest of the components such as CPU and RAM. Because of this, we recommend that disk I/O be cut down to a minimum where possible and reasonable. The general recommendations are a) don’t write to the logs unless strictly necessary, and b) don’t duplicate disk write.

                            This is not really a preference idea, but rather an efficiency idea.

                            With faster disks and better technology this is not as much as an issue as it used to be, but it still becomes an issue when volume and/or message size increases.

                            Personally, I recommend that message FILTERS almost always be logged so that the reason a message is filtered can quickly be determined. In this case, the I/O is worth the cost. I then recommend all other process logging be turned off unless there is a worthwhile reason to leave it on. And finally, use SMAT for message logging instead of writing messages to process logs.

                            -- Max Drown (Infor)

                        Viewing 11 reply threads
                        • The forum ‘Cloverleaf’ is closed to new topics and replies.