Repeating MDM Message

Yes, I was waiting for an Ack, and that’s where I was going with this.  I’ve adjusted my wait time downward as it was originally set pretty high, and now I’m waiting for some messages to come through so that I can see what’s going on.

I may have found the issue.  Here’s the end of the message that keeps repeating:  |||||||D

Here’s the end of the same interface in Test, that does not repeat:  ||||||R|Dx0d’

I’m going back to the sender to find out why I’m not getting that HEX to end the message in PROD when I got it in TEST.

This has become more perplexing.  When I look at the message with a HEX editor, the x0d is at the end of the message.  However, when I watch the output as the message is sent, the message is not encapsulated like similar messages from other systems.  For example, our Radiology system sends an MDM message that is like this ‘MSH……..OBX…|||Dx0d’, but this system is sending the message that looks like this:  MSH….OBX…||D in the output.  I’m not sure why the single quotes and the x0d are missing.

When I set up the thread, I used the Protocol pdl-tcip like I always do, and then used the mlp_tcp.pdl.  Do I need to use a different pdl?

Here are the details…

When this happens, in the recovery database, the message is in state 14 sending from the Receiving thread to the Receiving thread.  Here’s a screen shot

Created  Message Id     s e d Prio State Length Source          Dest

---

---

– – – —-

---

---

---

---

12:55:16 [0.0.213859943 P D N 8193    14   3063 to_logi_appt    to_logi_appt

To get this infinite loop stopped, I have to delete this message, and bounce the to_logi_appt thread.  I’ve excluded the translation as the culprit as this happens with the RAW message as well.  to_logi_appt has received messages for years with the same configuration without problem.  I have the sending thread set up the same way I have the other threads, so I’m not sure why this infinite loop is happening.

This is what I see in the logs from the end of the message to when it starts sending it again:

exercise, weight loss. Follow up in clinic every 3 to 6 months and p.r.n.~~~Skaggs Medical West~~Voice Job ID#:  456053/344360~D: 03/28/2014 18:48:55~T: 03/29/2014 04:43:44~ cl||||||R|Dx0d’

[msg :Msg :INFO/0: to_logi_appt:04/02/2014 08:52:03] [0.0.213810637] Updating the recovery database

[dbi :rlog:INFO/1: to_logi_appt:04/02/2014 08:52:03] [0.0.213810637] Update msg in recovery db to state OB post-SMS

[icl :tcpi:INFO/0: to_logi_appt:04/02/2014 08:52:03] [0.0.213810637] Message receive complete

[pti :sche:INFO/1: to_logi_appt:04/02/2014 08:52:03] Thread has 0 ready events left.

[pd  :thrd:INFO/1: to_logi_appt:04/02/2014 08:52:03] OB-Data queue has 1 msgs

[pd  :thrd:INFO/1: to_logi_appt:04/02/2014 08:52:03] OB-Data queue has SOME work

[pti :sche:INFO/1: to_logi_appt:04/02/2014 08:52:03] Thread has 1 ready events.

[pd  :thrd:INFO/1: to_logi_appt:04/02/2014 08:52:03] OB-Data queue has 1 msgs

[pd  :thrd:INFO/1: to_logi_appt:04/02/2014 08:52:03] OB-Data queue has SOME work

[pd  :thrd:INFO/0: to_logi_appt:04/02/2014 08:52:03] Processing OB-Data message queue

[pd  :pdtd:INFO/0: to_logi_appt:04/02/2014 08:52:03] [0.0.213810637] Writing message to Protocol Driver pdl-tcpip

[pdl :wrte:INFO/1: to_logi_appt:04/02/2014 08:52:03] [0.0.213810637] Write msg to connection

[pd  :pdtd:INFO/1: to_logi_appt:04/02/2014 08:52:03] [0.0.213810637] Writing message succeeded

[pd  :pdtd:INFO/0: to_logi_appt:04/02/2014 08:52:03] NOW AWAITING A REPLY!

[pd  :pdtd:INFO/1: to_logi_appt:04/02/2014 08:52:03] [0.0.213810637] Latencies: Outbound 0.006, Que 0.010, Total 0.019 secs

[dbi :rlog:INFO/1: to_logi_appt:04/02/2014 08:52:03] [0.0.213810637] Update msg in recovery db to state OB delivered OK

[pd  :pdtd:INFO/2: to_logi_appt:04/02/2014 08:52:03] [0.0.213810637] Writing msg to outbound save file to_logi_appt

[pd  :thrd:INFO/0: to_logi_appt:04/02/2014 08:52:03] [0.0.213810637] Invoking SENDOK

[pd  :pdtd:INFO/0: to_logi_appt:04/02/2014 08:52:03] [0.0.213810637] Executing send_data_ok TPS

[tps :tps :INFO/1: to_logi_appt:04/02/2014 08:52:03] tds.string = sendOK_save {MSGID message0} {CONTEXT send_data_ok} {ARGS {}} {MODE run} {VERSION 3.0}

[pti :sche:INFO/1: to_logi_appt:04/02/2014 08:52:03] Thread has 0 ready events left.

[pti :sche:INFO/2:to_logi_oru_url:04/02/2014 08:52:03] Performing apply callback for thread 2

[pti :sche:INFO/2:  fr_muse_url:04/02/2014 08:52:03] Performing apply callback for thread 3

[pti :sche:INFO/2: to_logi_appt:04/02/2014 08:52:03] Performing apply callback for thread 4

[pti :sche:INFO/1: to_logi_appt:04/02/2014 08:52:13] Thread has 1 ready events.

[pd  :pdtd:INFO/0: to_logi_appt:04/02/2014 08:52:13] [0.0.213810640] Executing reply_gen TPS

[tps :tps :INFO/1: to_logi_appt:04/02/2014 08:52:13] tds.string = resend_ob_msg {MSGID message1} {CONTEXT reply_gen} {ARGS {}} {MODE run} {VERSION 3.0}

[pd  :thrd:INFO/0: to_logi_appt:04/02/2014 08:52:13] [0.0.213810637] Placing msg on OB post-SMS DATA queue

[pd  :pdtd:INFO/3: to_logi_appt:04/02/2014 08:52:13] [0.0.213810637] OB post-SMS message details

msg: 0x30002e28

   msgType           : DATA

   msgClass          : PROTOCOL

   msgState          : OB delivered OK (14)

   msgPriority       : 8193

   msgRecoveryDbState: 3

   msgFlags          : 0x8206

   msgMid            : [0.0.213810637]

   msgSrcMid         : [0.0.213810634]

   msgSrcMidGroup    : midNULL

   msgOrigSrcThread  : fr_escription

   msgOrigDestThread : to_logi_appt

   msgSrcThread      : to_logi_appt

   msgDestThread     : to_logi_appt

   msgXlateThread    :

   msgSkipXlate      : 0

   msgSepChars       :

   msgNumRetries     : 0

   msgGroupId        : 0

   msgDriverControl  :

   msgRecordFormat   :

   msgRoutes         :

   msgUserData       :

   msgStaticIsDirty  : 1

   msgVariableIsDirty: 0

   msgTimeStartIb    : 1396446733.782

   msgTimeStartOb    : 1396446723.775

   msgTimeCurQueStart: 0.000

   msgTimeTotalQue   : 0.010

   msgTimeRecovery   : 1396446723.773

   msgEoConfig       : 0x0

   msgData (BO)      : 0x30002ed4

   message           : ‘MSH|^~&|DICTAPHONE|COX|HNA|COX|20140331093207||MDM^T02|20140331093207|P|2.3x0dEVN|T02|20140331093207x0dPID||01455

I solved the issue… finally.

The problem was with the ACK/NAK and one not being sent back by the receiving system.  I finally tracked it down to the sending system not sending a value in MSH 15, which specifies how ACK/NAK are supposed to be handled.  

In the system we’re replacing, that system always sent “AL” in that field, to specify that there should always be an ACK or NAK, so I mapped AL to MSH 15 in my translation, and now I have messages flowing correctly between the two systems.

Thanks everyoe, espcially Jim Kosloskey for your help!