› Clovertech Forums › Read Only Archives › Cloverleaf › Cloverleaf › SMAT does not Save Inbound – No errors or entries in DB
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.
[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
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.
Client was bypassing Cloverleaf and connecting directly to application parsing mechanism. Thanks Jim!
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.