SMAT does not Save Inbound – No errors or entries in DB

Clovertech Forums Read Only Archives Cloverleaf Cloverleaf SMAT does not Save Inbound – No errors or entries in DB

  • Creator
    Topic
  • #51752
    mark davis
    Participant

      This thread issue (his_order) is similar to the 2008 thread ‘Rev 2 mlp_tcp’ with a few important differences: 1) my issue is inbound, and 2) hcidbdump has NO entries. Sometimes hcidbinit is run (these tend to be new machines), so there are not many entries in the recovery and error databases, but usually there is at least one entry. The inability to see/capture new transactions inbound has been problematic. Any insight appreciated.

      Equipment: Windows Server 2003 R2, SP2, QDX 5.3, client 5.3P_REV5

      Procs on his_order (inbound thread): RawHL7Ack (IB)

      Procs on gemsit_orders (outbound thread): validate_reply, kill_ob_save, hcitpsmsgkill (OB – OB Only checked on IB thread)

      Inbound log attached with enable_all active.

    Viewing 3 reply threads
    • Author
      Replies
      • #71597
        mark davis
        Participant

          mark davis wrote:

          [prod:prod:INFO/0:  STARTUP_TID] Copyright 1993-2007, Quovadx Inc.

          [prod:prod:INFO/0:  STARTUP_TID] QDX(TM) Integration Services 5.3P Rev5

          [prod:prod:INFO/0:  STARTUP_TID] Linked by Administrator on swatch at Mon Apr 23 15:34:29 2007 in C:/cloverrel/cloverleaf/engine/main (build 143)

          [prod:prod:INFO/0:  STARTUP_TID] Started at Wed May 12 11:34:28 2010

          [prod:prod:INFO/0:  STARTUP_TID] Engine process is 5080 on host MS720

          [prod:prod:INFO/1:  inbound_cmd] Msg space limit is 100

          [prod:prod:INFO/0:  inbound_cmd] DiskQue Minimum # of Messages/que: 50

          [prod:prod:INFO/0:  inbound_cmd] DiskQue Virtual Memory percent:75.000000

          [prod:prod:INFO/0:  inbound_cmd] Applying EO config: ”

          [prod:prod:INFO/0:inbound_xlate] Applying EO config: ”

          [prod:prod:INFO/0:    his_order] Applying EO config: ‘enable_all’

          [msi :msi :INFO/1:    his_order] Initializing statistics for: his_order

          [diag:leak:DBUG/0:    his_order] diag mtd alloc 0x00AB9410

          [diag:leak:DBUG/0:    his_order] diag mts alloc 0x00AB94B8

          [diag:leak:DBUG/0:    his_order] diag mis alloc 0x00AB9588

          [diag:leak:DBUG/0:    his_order] diag timeval alloc 0x00AB49F8

          [diag:leak:DBUG/0:    his_order] diag timeval alloc 0x003E7C70

          [diag:leak:DBUG/0:    his_order] diag ev alloc 0x00AB9438

          [diag:leak:DBUG/0:    his_order] diag dqe alloc 0x00AB93B8

          [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER () event 0x00AB9438 for tid 2

          [diag:leak:DBUG/0:    his_order] diag ele alloc 0x00AB93A0

          [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER event for tid 2

          [diag:leak:DBUG/0:    his_order] diag timeval free  0x003E7C70

          [msi :msi :DBUG/1:    his_order] msiSetExportTimer: 5 second timer event set

          [pd  :thrd:INFO/0:    his_order] Performing database recovery

          [dbi :log :INFO/1:    his_order] Scanning Recovery DB for selected messages

          [dbi :log :INFO/1:    his_order] Messages limited to those owned by:

          [dbi :log :INFO/1:    his_order] his_order

          [pd  :thrd:INFO/0:    his_order] Database recovery complete

          [pd  :pdtd:INFO/0:    his_order] Initializing Protocol Driver

          [diag:leak:DBUG/0:    his_order] diag pd alloc 0x00AB6840

          [pdl :init:INFO/1:    his_order] Initializing

          [diag:leak:DBUG/0:    his_order] diag pdl alloc 0x00AB9980

          [pdl :init:DBUG/0:    his_order] PDL Name: ‘mlp_tcp.pdl’

          [pdl :open:DBUG/0:    his_order] PDL Config: ‘{TYPE tcp-server} {PORT 4001} {NAME mlp_tcp.pdl} {MODE None} {IS_SSL 0} {CA_FILE {}} {CA_PATH {}} {CERT_FILE {}} {PRIVATE_KEY {}} {PASSWORD {}} {CERT_TYPE PEM} {KEY_TYPE PEM}’

          [diag:leak:DBUG/0:    his_order] diag timeval alloc 0x00AB67F0

          [pd  :pdtd:INFO/1:    his_order] Set driver status to PD_STATUS_OPENING

          [pdl :open:INFO/0:    his_order] Loading PDL driver ‘mlp_tcp.pdl’

          [pdl :PDL :DBUG/0:    his_order] Loading driver: c:/gehc-it/ccg/quovadx/qdx5.3/integrator/pdls/mlp_tcp.pdo

          [msg :Mid :DBUG/3:    his_order] Opening mid ctr file c:gehc-itccgquovadxqdx5.3integratorhis_prod/exec/mid

          [dbi :elog:DBUG/3:    his_order] [0.0.61611] Looking for mid in error db

          [dbi :rlog:DBUG/3:    his_order] [0.0.61611] Looking for mid in recovery db

          [msg :Mid :DBUG/3:    his_order] Assigned mid [0.0.61611] to msg 003EB590

          [msg :Msg :DBUG/0:    his_order] [0.0.61611] MSG alloc 0x003EB590

          [pdl :PDL :DBUG/0:    his_order] Loaded: tcpip-mlp (version 2.0)

          [pdl :PDL :DBUG/0:    his_order] Evaling:

                 proc hci_pd.write { info } {

             global MsgId

             

             keylget info message MsgId

                     keylset continuations ok     write.done

                     keylset continuations error write.error

             keylset continuations timeout

               hci_pd_send basic-msg

              ] $continuations

                     }

                     proc write.done {info} {}

                     

                     proc write.error {info} {

                         hci_pd_report_exception 1 “write failure”

                 hci_pd_set_result_code 1

                     }

                     

              proc write.timeout {info} {

                 global MsgId

                         msgmetaset $MsgId FLAGS {{proto_timeout 1}}

                         hci_pd_set_result_code 1

              }

              proc hci_pd.read {info} {

                 keylset continuations basic-msg read.done

                 keylset continuations error read.error

                 keylset continuations timeout

                 hci_pd_receive $continuations

              }

              proc read.done {info} {

                 keylset accept text

                ]

                   keylset accept end [keylget info end]

                   hci_pd_accept $accept

                }

                proc read.error {info} {

                   

                   keylget info type type

                   switch -exact — $type {

                input-error {

                   hci_pd_report_exception 1 “device error (remote side probably shut down)”

                   hci_pd_ignore_input -all

                }

                no-match {

                   hci_pd_ignore_input 1

                   hci_pd_ignore_input -until xb

                }

                default {

                   hci_pd_report_exception 2 “unknown fail: $type”

                   hci_pd_ignore_input -all

                }

                   }

                }

                proc read.timeout {info} {

                   hci_pd_ignore_input 1

                   hci_pd_ignore_input -until xb

                }

                [pdl :PDL :DBUG/2:    his_order] PDL changed states: old 7, new 4

                [pdl :PDL :DBUG/0:    his_order] Calling Tcl procedure: hci_pd.initialize

                [pdl :PDL :DBUG/0:    his_order] with args: {}

                [pdl :PDL :DBUG/0:    his_order] Tcl procedure hci_pd.initialize returns ”

                [pdl :PDL :DBUG/1:    his_order] Creating PDL listen event on fd 1244

                [diag:leak:DBUG/0:    his_order] diag ev alloc 0x00ABA7A0

                [pti :even:DBUG/0:    his_order] Registering SOCKET (PDL server) event 0x00ABA7A0 for tid 2

                [diag:leak:DBUG/0:    his_order] diag ele alloc 0x00ABA7E8

                [pti :even:DBUG/0:    his_order] Registering SOCKET event for tid 2

                [pti :even:DBUG/1:    his_order] Associated WSAEvent 1220 with READ condition on socket 1244 (0x3d)

                [pd  :pdtd:INFO/1:    his_order] Initializing ACK Control TPS

                [pd  :pdtd:INFO/1:    his_order] Initializing data prewrite TPS

                [pd  :pdtd:INFO/1:    his_order] Initializing reply prewrite TPS

                [pd  :pdtd:INFO/1:    his_order] Initializing data send OK TPS

                [pd  :pdtd:INFO/1:    his_order] Initializing reply send OK TPS

                [pd  :pdtd:INFO/1:    his_order] Initializing data send fail TPS

                [pd  :pdtd:INFO/1:    his_order] Initializing reply send fail TPS

                [pd  :pdtd:INFO/1:    his_order] Initializing reply generation TPS

                [sms :sms :INFO/0:    his_order] SMS Initializing the SMS module for his_order

                [diag:leak:DBUG/0:    his_order] diag std alloc 0x00ABA880

                [diag:leak:DBUG/0:    his_order] diag sms alloc 0x00ABA8A0

                [diag:leak:DBUG/0:    his_order] diag sms alloc 0x00ABA8E0

                [diag:leak:DBUG/0:    his_order] diag sms alloc 0x00ABA900

                [diag:leak:DBUG/0:    his_order] diag sms alloc 0x00ABA920

                [sms :sms :INFO/0:    his_order] Initialize the IB data SMS stack

                [sms :sms :INFO/0:    his_order] [midNULL] Driver processing msg

                [diag:leak:DBUG/0:    his_order] diag tc alloc 0x00ABA940

                [tps :tps :INFO/1:    his_order] tds.string = RawHl7Ack {CONTEXT sms_ib_data} {ARGS {}} {MODE start} {VERSION 3.0}

                [tps :tps :INFO/1:    his_order] tds.string = show_msg {CONTEXT sms_ib_data} {ARGS {{DEBUG 1}}} {MODE start} {VERSION 3.0}

                [sms :sms :INFO/0:    his_order] Initialize the IB reply SMS stack

                [sms :sms :INFO/0:    his_order] [midNULL] Driver processing msg

                [diag:leak:DBUG/0:    his_order] diag tc alloc 0x00ABA998

                [sms :sms :INFO/0:    his_order] Initialize the OB data SMS stack

                [sms :sms :INFO/0:    his_order] [midNULL] Driver processing msg

                [diag:leak:DBUG/0:    his_order] diag tc alloc 0x00ABA9F0

                [sms :sms :INFO/0:    his_order] Initialize the OB reply SMS stack

                [sms :sms :INFO/0:    his_order] [midNULL] Driver processing msg

                [diag:leak:DBUG/0:    his_order] diag tc alloc 0x00ABAA48

                [pd  :pdtd:INFO/0:    his_order] Throwing startup control switches

                [pd  :pdtd:INFO/0:    his_order] Throwing OB post-SMS dequeue switch

                [icl :conn:DBUG/0:    his_order] ICL Closing connection to inbound_xlate

                [icl :conn:DBUG/0:    his_order] ICL Closing connection cache entry for inbound_xlate

                [icl :conn:DBUG/0:    his_order] ICL Opening connection to thread inbound_xlate

                [diag:leak:DBUG/0:    his_order] diag ite alloc 0x003EF688

                [icl :conn:DBUG/0:    his_order] ICL Using a PTHREADS connection

                [diag:leak:DBUG/0:    his_order] diag conn alloc 0x00ABAAC0

                [icl :conn:DBUG/0:    his_order] ICL Opening connection cache entry for inbound_xlate

                [diag:leak:DBUG/0:    his_order] diag ite free 0x003EF688

                [icl :icl :DBUG/2:    his_order] Sending to thread ‘inbound_xlate’, command ‘pstart his_order’

                [diag:leak:DBUG/0:    his_order] diag imh alloc 0x00ABAB10

                [diag:leak:DBUG/0:    his_order] diag ptm alloc 0x00ABAB30

                [pti :msg :DBUG/1:    his_order] Send PTM 0x00ABAB30 from 2 to 1: data 0x00ABAB10

                [xlt :thre:DBUG/1:    his_order] Notifying processes of new thread

                [xlt :thre:DBUG/1:    his_order] Open New Thread Event, name: c:gehc-itccgquovadxqdx5.3integratorhis_prod/outbound/NTE

                [prod:prod:INFO/0:      his_adt] Applying EO config: ”

                [prod:prod:INFO/0:   gemsit_adt] Applying EO config: ”

                Inside checkForValidADTEvents

                [prod:prod:INFO/0:gemsit_orders] Applying EO config: ”

                [pti :sche:INFO/2:    his_order] Performing apply callback for thread 2

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                [pti :sche:INFO/2:    his_order] Performing apply callback for thread 2

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                [pti :sche:INFO/2:    his_order] Performing apply callback for thread 2

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                [pti :sche:INFO/2:    his_order] Performing apply callback for thread 2

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                Engine idle — 05/12/2010 11:34:40

                [pti :sche:DBUG/2:    his_order] Thread 2 has been enabled

                [pti :sche:INFO/1:    his_order] Thread has 1 ready events.

                [pti :even:DBUG/0:    his_order] Processing ACTIVE_TIMER () event 0x00AB9438

                [pti :even:DBUG/1:    his_order] Calling cb 0x521253

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                [pti :even:DBUG/0:    his_order] Unregistering ACTIVE_TIMER () event 0x00AB9438 for tid 2

                [pti :even:DBUG/0:    his_order] evUnregister ACTIVE_TIMER event 0xAB9438 for tid 2

                [diag:leak:DBUG/0:    his_order] diag timeval alloc 0x00AD69C0

                [diag:leak:DBUG/0:    his_order] diag dqe alloc 0x00AC9A38

                [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER () event 0x00AB9438 for tid 2

                [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER event for tid 2

                [diag:leak:DBUG/0:    his_order] diag timeval free  0x00AD69C0

                [pti :sche:INFO/1:    his_order] Thread has 0 ready events left.

                Valid Message type

                [pti :sche:INFO/2:    his_order] Performing apply callback for thread 2

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                Engine idle — 05/12/2010 12:41:16

                [pti :sche:DBUG/2:    his_order] Thread 2 has been enabled

                [pti :sche:INFO/1:    his_order] Thread has 1 ready events.

                [pti :even:DBUG/0:    his_order] Processing ACTIVE_TIMER () event 0x00AB9438

                [pti :even:DBUG/1:    his_order] Calling cb 0x521253

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                [pti :even:DBUG/0:    his_order] Unregistering ACTIVE_TIMER () event 0x00AB9438 for tid 2

                [pti :even:DBUG/0:    his_order] evUnregister ACTIVE_TIMER event 0xAB9438 for tid 2

                [diag:leak:DBUG/0:    his_order] diag timeval alloc 0x00AC9948

                [diag:leak:DBUG/0:    his_order] diag dqe alloc 0x00AC3228

                [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER () event 0x00AB9438 for tid 2

                [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER event for tid 2

                [diag:leak:DBUG/0:    his_order] diag timeval free  0x00AC9948

                [pti :sche:INFO/1:    his_order] Thread has 0 ready events left.

                Valid Message type

                [pti :sche:INFO/2:    his_order] Performing apply callback for thread 2

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                Engine idle — 05/12/2010 12:43:04

                [pti :sche:DBUG/2:    his_order] Thread 2 has been enabled

                [pti :sche:INFO/1:    his_order] Thread has 1 ready events.

                [pti :even:DBUG/0:    his_order] Processing ACTIVE_TIMER () event 0x00AB9438

                [pti :even:DBUG/1:    his_order] Calling cb 0x521253

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                [pti :even:DBUG/0:    his_order] Unregistering ACTIVE_TIMER () event 0x00AB9438 for tid 2

                [pti :even:DBUG/0:    his_order] evUnregister ACTIVE_TIMER event 0xAB9438 for tid 2

                [diag:leak:DBUG/0:    his_order] diag timeval alloc 0x00AC9948

                [diag:leak:DBUG/0:    his_order] diag dqe alloc 0x00AC3228

                [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER () event 0x00AB9438 for tid 2

                [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER event for tid 2

                [diag:leak:DBUG/0:    his_order] diag timeval free  0x00AC9948

                [pti :sche:INFO/1:    his_order] Thread has 0 ready events left.

                Valid Message type

                [pti :sche:INFO/2:    his_order] Performing apply callback for thread 2

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                Engine idle — 05/12/2010 13:17:25

                [pti :sche:DBUG/2:    his_order] Thread 2 has been enabled

                [pti :sche:INFO/1:    his_order] Thread has 1 ready events.

                [pti :even:DBUG/0:    his_order] Processing ACTIVE_TIMER () event 0x00AB9438

                [pti :even:DBUG/1:    his_order] Calling cb 0x521253

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                [pti :even:DBUG/0:    his_order] Unregistering ACTIVE_TIMER () event 0x00AB9438 for tid 2

                [pti :even:DBUG/0:    his_order] evUnregister ACTIVE_TIMER event 0xAB9438 for tid 2

                [diag:leak:DBUG/0:    his_order] diag timeval alloc 0x00AC9948

                [diag:leak:DBUG/0:    his_order] diag dqe alloc 0x00AB93B8

                [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER () event 0x00AB9438 for tid 2

                [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER event for tid 2

                [diag:leak:DBUG/0:    his_order] diag timeval free  0x00AC9948

                [pti :sche:INFO/1:    his_order] Thread has 0 ready events left.

                Valid Message type

                [pti :sche:INFO/2:    his_order] Performing apply callback for thread 2

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                Engine idle — 05/12/2010 13:24:05

                [pti :sche:DBUG/2:    his_order] Thread 2 has been enabled

                [pti :sche:INFO/1:    his_order] Thread has 1 ready events.

                [pti :even:DBUG/0:    his_order] Processing ACTIVE_TIMER () event 0x00AB9438

                [pti :even:DBUG/1:    his_order] Calling cb 0x521253

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                [pti :even:DBUG/0:    his_order] Unregistering ACTIVE_TIMER () event 0x00AB9438 for tid 2

                [pti :even:DBUG/0:    his_order] evUnregister ACTIVE_TIMER event 0xAB9438 for tid 2

                [diag:leak:DBUG/0:    his_order] diag timeval alloc 0x00AC9948

                [diag:leak:DBUG/0:    his_order] diag dqe alloc 0x00AD7AB8

                [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER () event 0x00AB9438 for tid 2

                [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER event for tid 2

                [diag:leak:DBUG/0:    his_order] diag timeval free  0x00AC9948

                [pti :sche:INFO/1:    his_order] Thread has 0 ready events left.

                Valid Message type

                [pti :sche:INFO/2:    his_order] Performing apply callback for thread 2

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                Engine idle — 05/12/2010 13:25:35

                [pti :sche:DBUG/2:    his_order] Thread 2 has been enabled

                [pti :sche:INFO/1:    his_order] Thread has 1 ready events.

                [pti :even:DBUG/0:    his_order] Processing ACTIVE_TIMER () event 0x00AB9438

                [pti :even:DBUG/1:    his_order] Calling cb 0x521253

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                [pti :even:DBUG/0:    his_order] Unregistering ACTIVE_TIMER () event 0x00AB9438 for tid 2

                [pti :even:DBUG/0:    his_order] evUnregister ACTIVE_TIMER event 0xAB9438 for tid 2

                [diag:leak:DBUG/0:    his_order] diag timeval alloc 0x00AC9948

                [diag:leak:DBUG/0:    his_order] diag dqe alloc 0x003EFAD8

                [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER () event 0x00AB9438 for tid 2

                [pti :even:DBUG/0:    his_order] Registering ACTIVE_TIMER event for tid 2

                [diag:leak:DBUG/0:    his_order] diag timeval free  0x00AC9948

                [pti :sche:INFO/1:    his_order] Thread has 0 ready events left.

                Valid Message type

                [pti :sche:INFO/2:    his_order] Performing apply callback for thread 2

                [msi :msi :DBUG/1:    his_order] msiExportStats: export for thread: his_order

                Engine idle — 05/12/2010 13:35:28

            • #71598
              Jim Kosloskey
              Participant

                Mark,

                Maybe I am not reading this correctly but it does not look like a message ever arrived to that connection.

                No message – no SMAT and certainly no Recovery DB activity.

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

              • #71599
                mark davis
                Participant

                  Client was bypassing Cloverleaf and connecting directly to application parsing mechanism. Thanks Jim!

                • #71600
                  Jim Kosloskey
                  Participant

                    That’ll do it!!

                    Every client/user thinks they know better.

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

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