5.7 Obscure Repeating "Receiving A Command" messag

Clovertech Forums Read Only Archives Cloverleaf Cloverleaf 5.7 Obscure Repeating "Receiving A Command" messag

  • Creator
    Topic
  • #51932
    Jennifer Hardesty
    Participant

      We have this process with 5 inbound threads/connections from other sites and interface engines and 7 outbound threads/connections/ports to a particular ip address.  Everything works fine in Cloverleaf 5.4; in fact, it’s all pretty basic with simple routes, tclproc filters, Xlates, etc for adt, merges, labs, and text-based messages for 3 facilities.

      Now that it’s set up in 5.7, the log file is filling up with a repeating INFO/error message regarding what I assume is a dropped connection.  However, all the connections show as “UP” continuously.  I have tried to turn all of the threads off while leaving the process on, the repeating message continues.

      I’ve double checked for ports being used twice.  I turned on “enable all” but there doesn’t seem to be any extra info around these particular lines in the log.

      Code:


      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:45:04] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:45:04] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:45:04] Received command: ‘hin_xlate xrel_post’
      [cmd :cmd :INFO/0:    hin_xlate:08/16/2010 02:45:04] Doing ‘xrel_post’ command with args ‘
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:45:04] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:45:04] Command client went away.  Closing connection.
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:45:04] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:45:05] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:45:05] Received command: ”hin_xlate’
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:45:05] Cmd null in ”hin_xlate’
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:45:05] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:45:05] Command client went away.  Closing connection.
      Engine idle — 08/16/2010 02:45:15

      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:47:13] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:47:13] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:47:13] Received command: ‘hin_xlate xrel_post’
      [cmd :cmd :INFO/0:    hin_xlate:08/16/2010 02:47:13] Doing ‘xrel_post’ command with args ‘
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:47:13] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:47:13] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:47:13] Command client went away.  Closing connection.
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:47:13] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:47:13] Received command: ”hin_xlate’
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:47:13] Cmd null in ”hin_xlate’
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:47:13] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:47:13] Command client went away.  Closing connection.
      Engine idle — 08/16/2010 02:47:23

      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:49:18] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:49:18] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:49:18] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:49:18] Received command: ‘hin_xlate xrel_post’
      [cmd :cmd :INFO/0:    hin_xlate:08/16/2010 02:49:18] Doing ‘xrel_post’ command with args ‘
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:49:18] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:49:18] Received command: ”hin_xlate’
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:49:18] Cmd null in ”hin_xlate’
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:49:18] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:49:18] Command client went away.  Closing connection.
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:49:18] Receiving a command
      [cmd :cmd :INFO/0:      hin_cmd:08/16/2010 02:49:18] Command client went away.  Closing connection.
      Engine idle — 08/16/2010 02:49:28

      Has anyone seen this?  Fixed it?  Please help!!!!  This has me stumped.

    Viewing 9 reply threads
    • Author
      Replies
      • #72347
        John Mercogliano
        Participant

          Jennifer,

           I’m assuming you have a process called hin?  It appears you possibly have either a cron job or an alert that is executing some form of the following command

          Code:

          hcicmd -p hin -c “hin_xlate xrel_post”

          The second one would be an error as it would represent a command of

          Code:

          hcicmd -p hin -c “hin_xlate”


          Or it is just a misconfigured alert on this process that did not transfer well from 5.4. and Cloverleaf is now misfiring it.

          Both these those commands are using the monitord to send commands to the xlate queue, in this case attemping to release a hold on the post xlate queue.  

           I hope this helps in your investigation.

          John Mercogliano
          Sentara Healthcare
          Hampton Roads, VA

        • #72348
          Greg Eriksen
          Participant

            John, you were on the right track about it having to do with an alert.

            I work on the same team as Jennifer, and it appears these INFO messages were showing up in the logs of ALL the processes in that site.

            I had a Last Received alert configured on an interface I was developing, which excuted a pstop and pstart of the affected thread.  For some reason it was causing these INFO messages to get posted to the logs of the other processes in that site.  Maybe that’s normal, but it was pretty obnoxious because the alert was triggering every 2 minutes.  I’ve deleted the alert, and the only remaining INFO messages we are now seeing in the logs appear to be from some crontab scripts that also do stops and starts of threads.

          • #72349
            Jennifer Hardesty
            Participant

              What I do not understand is why crontab jobs and alert messages that affect other threads in the same site are causing these messages to appear in the hin process log file.  There are no crontab jobs that stop/start the hin process and no alerts set up on this server for this process and yet these messages continue to occur.  They are not only distracting and fill up the log file unnecessarily but they provide inaccurate and misleading information.

            • #72350
              John Mercogliano
              Participant

                Gregg,

                   Is this an outbound thread?  Do you have any cross process communication going on?  When a thread starts up, it sends a message xrel_post message to all processes that the thread has a route associated with.  So, if you are in your own process but you have a route from every inbound thread, and you bounce every two minutes, then every two minutes they will get this message.  In affect, the thread is saying, I’m back up and ready to receive messages again.

                Hope this helps,

                John Mercogliano
                Sentara Healthcare
                Hampton Roads, VA

              • #72351
                Jennifer Hardesty
                Participant

                  There is no cross-process communication on that site.  It’s pretty much a bunch of self-contained little processes.  Plus, all of the cronjobs have to do with processes other than hin.

                  I just don’t know why when other processes stop and start, it appears in the hin log as above.  It’s misleading.

                • #72352
                  Michael Hertel
                  Participant

                    If I remember

                  • #72353
                    John Mercogliano
                    Participant

                      Jennifer,

                      John Mercogliano
                      Sentara Healthcare
                      Hampton Roads, VA

                    • #72354
                      Greg Eriksen
                      Participant

                        Thanks Michael and John, I think I have a much better understanding now of what was going on (and John, your explanation of the “why” sounds plausible).

                        The alert was for a Philips vital signs feed that was expected to be very reliable and consistant throughout the entire day, so not recieving any messages for as little as 90 seconds was considered to be proof there was a problem.  If the Philips server was ever rebooted, it did not send a tcp/ip signal about the disconnect, so the engine side stayed in an “up” status, connected to a dead socket number.  The exec action for the alert was to bounce the thread repeatedly until it reestablished a connection.   The problem in our test environment was that as we prepped for a go-live, the clinical engineer shut off the feed to test and used it for the new prod connection.  Thus, the alert started triggering every two minutes because it wasn’t receiving messages any more.

                      • #72355
                        John Mercogliano
                        Participant

                          Gregg,

                            We have phillips also, suggestion.  You should not have to bounce repeatedly.  The first time you bounce should free the dead socket and place you in an opening state.  Once there you should be able to have another alert to monitor for opening and if its there to long its because they obviously they have not notices the connection is down on there side.  At least my experience with the device monitors, when they come back up while we are in opening they reconnect fine.  You just need to free up the port from the dead socket from the previous connect.

                            It might depend on how they have device server configured but it could relieve you of log overload if something happens in production and you start bouncing like crazy.

                          John Mercogliano
                          Sentara Healthcare
                          Hampton Roads, VA

                        • #72356
                          Greg Eriksen
                          Participant

                            John, thanks for the suggestion.  I had in fact originally made use of the new “repeat” functionality available to us in 5.7, and enabled a 1 minute repeat.  What I found when I disabled the repeat function was that the alert repeated every two minutes anyway, because each pstart of the thread “resets” the alert status, and the conditions ( >= 90 seconds, for duration of 30 seconds) become true again after 2 minutes and the alert triggers again.

                            The idea behind this alert was that the Philips feed should normally be constant and reliable, except for the infrequent occasions when they need to reboot one of their dbs servers to make a config change.

                            As it happens, this interface went live yesterday.  The users discovered that they weren’t getting vent data for 2 beds.  In the course of figuring out that they had incomplete bed mapping for the new connection, clinical engineering rebooted their server twice during the day.  Both times, the alert performed as intended, and after a few repeats the server came back up, responded to the connection request, and the feed was reestablished. I understand that only one thread pstart is required to put the thread in a “listening” status, but because each thread start causes the alert status to be reset, and the conditions become true again after 2 minutes, I think a few repeats are inevitable.

                            As stated below, the problem in our test environment that Jennifer reported, was because clinical engineering completely shut down the feed to test to repurpose it for production, and I didn’t remember that I should disable or remove the alert.  However, I also hadn’t thought that the alert bouncing the thread repeatedly would pose a problem for anything else in that site.  But now we know that each pstart causes those INFO messages to show up in all process logs.

                            The alert currently in production also includes an email notification, so if the alert is firing endlessly it will fill up my inbox, and drive me to distraction rather than Jennifer.

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