tilln / jmeter-iso8583

ISO8583 Plugin for JMeter
MIT License
62 stars 32 forks source link

ISO message request failing with ReadTimeout error #34

Closed kulkarnihr closed 3 years ago

kulkarnihr commented 3 years ago

Hi,

I am using ISO8583 message sampler along with Jmeter 5.1.1 to send request to Switch. But every time I am sending request I see "n.c.b.j.i.Q2:(org.jpos.q2.ChannelAdaptor) Read timeout / EOF - reconnecting" message on jmeter console. And the request is failing with a response message as Timeout. I tried using different channels like ASCII, HEX, BCD, BASE. But seeing the same issue. However, I can successfully telnet to the said IP and port using command prompt. I have done all the set up as mentioned in Usage. Please refer below my request and console logs: Request :

Console output : 2020-12-16 15:33:16,752 DEBUG o.a.j.g.GuiPackage: Gui retrieved = org.apache.jmeter.visualizers.ViewResultsFullVisualizer[View Results Tree,0,0,922x568,invalid,layout=java.awt.BorderLayout,alignmentX=0.0,alignmentY=0.0,border=javax.swing.border.EmptyBorder@648c8dfb,flags=9,maximumSize=,minimumSize=,preferredSize=] 2020-12-16 15:33:16,752 DEBUG o.a.j.g.GuiPackage: Gui retrieved = org.apache.jmeter.visualizers.StatVisualizer[Aggregate Report,0,0,0x0,invalid,layout=java.awt.BorderLayout,alignmentX=0.0,alignmentY=0.0,border=,flags=9,maximumSize=,minimumSize=,preferredSize=] 2020-12-16 15:33:16,752 DEBUG o.a.j.g.GuiPackage: Gui retrieved = org.apache.jmeter.visualizers.ViewResultsFullVisualizer[View Results Tree,0,0,922x568,invalid,layout=java.awt.BorderLayout,alignmentX=0.0,alignmentY=0.0,border=javax.swing.border.EmptyBorder@75328a16,flags=9,maximumSize=,minimumSize=,preferredSize=] 2020-12-16 15:33:23,534 DEBUG o.a.j.g.GuiPackage: Updating current node View Results Tree 2020-12-16 15:33:23,534 DEBUG o.a.j.g.GuiPackage: Gui retrieved = org.apache.jmeter.visualizers.ViewResultsFullVisualizer[View Results Tree,0,0,922x568,invalid,layout=java.awt.BorderLayout,alignmentX=0.0,alignmentY=0.0,border=javax.swing.border.EmptyBorder@75328a16,flags=9,maximumSize=,minimumSize=,preferredSize=] 2020-12-16 15:33:23,534 DEBUG o.a.j.g.AbstractJMeterGuiComponent: setting element to enabled: true 2020-12-16 15:33:23,534 DEBUG o.a.j.g.GuiPackage: Gui retrieved = org.apache.jmeter.visualizers.ViewResultsFullVisualizer[View Results Tree,0,0,922x568,invalid,layout=java.awt.BorderLayout,alignmentX=0.0,alignmentY=0.0,border=javax.swing.border.EmptyBorder@75328a16,flags=9,maximumSize=,minimumSize=,preferredSize=] 2020-12-16 15:33:23,534 WARN o.a.j.g.a.LogLevelCommand: Setting root log level: INFO 2020-12-16 15:33:34,302 INFO o.a.j.e.StandardJMeterEngine: Running the test! 2020-12-16 15:33:34,302 INFO o.a.j.s.SampleEvent: List of sample_variables: [] 2020-12-16 15:33:34,305 INFO n.c.b.j.i.Q2: (Q2.system) Q2 started, deployDir=D:\apache-jmeter-5.1.1\apache-jmeter-5.1.1\bin\deploy, environment=default 2020-12-16 15:33:34,316 INFO o.a.j.g.u.JMeterMenuBar: setRunning(true, local) 2020-12-16 15:33:34,344 INFO o.a.j.e.StandardJMeterEngine: Starting ThreadGroup: 1 : Thread Group 2020-12-16 15:33:34,344 INFO o.a.j.e.StandardJMeterEngine: Starting 1 threads for group Thread Group. 2020-12-16 15:33:34,344 INFO o.a.j.e.StandardJMeterEngine: Thread will continue on error 2020-12-16 15:33:34,344 INFO o.a.j.t.ThreadGroup: Starting thread group... number=1 threads=1 ramp-up=1 delayedStart=false 2020-12-16 15:33:34,344 INFO o.a.j.t.ThreadGroup: Started thread group number 1 2020-12-16 15:33:34,345 INFO o.a.j.e.StandardJMeterEngine: All thread groups have been started 2020-12-16 15:33:34,347 INFO o.a.j.t.JMeterThread: Thread started: Thread Group 1-1 2020-12-16 15:33:37,295 WARN n.c.b.j.i.Q2: (org.jpos.q2.iso.ChannelAdaptor) channel-receiver-jmeter-3288c4ff-receive 2020-12-16 15:33:37,295 WARN n.c.b.j.i.Q2: (org.jpos.q2.iso.ChannelAdaptor) Read timeout / EOF - reconnecting 2020-12-16 15:33:54,357 INFO o.a.j.t.JMeterThread: Thread is done: Thread Group 1-1 2020-12-16 15:33:54,357 INFO o.a.j.t.JMeterThread: Thread finished: Thread Group 1-1 2020-12-16 15:33:54,357 INFO o.a.j.e.StandardJMeterEngine: Notifying test listeners of end of test 2020-12-16 15:33:54,359 INFO n.c.b.j.i.Q2: (Q2.system) shutting down 2020-12-16 15:33:54,359 INFO n.c.b.j.i.Q2: (Q2.system) shutdown done 2020-12-16 15:33:54,359 INFO o.a.j.g.u.JMeterMenuBar: setRunning(false, local)

chhil commented 3 years ago

Is the entity you are communicating with sending anything other than the message like keep alives etc. Underlying jpos will calculate the message length and wait for those may bytes. If it doesn't receive them you will get a read timeout.

Or simply there is a channel mismatch between the 2 entities. Seems more jpos related than this plugin.

tilln commented 3 years ago

Hi @kulkarnihr

Perhaps you can turn up the log level, e.g. via command line jmeter -Lnz.co.breakpoint=DEBUG and post the log output. This may provide some more insights.

@chhil agree, more likely a jPOS issue.

leonartambunan commented 3 years ago

My case is different. The 0800 requests are successfully read by this plugin. But the 0210 messages (response to 0200) are not read although the packets are arrived (verified via Wireshark) and unpacked successfully (the log shows). I managed to add the logger.xml into the deploy folder to show more details of the plugin.

tilln commented 3 years ago

@leonartambunan can you please open a separate issue and attach log files as well as expected request and response message pairs?

leonartambunan commented 3 years ago

It turns out it is the MTI-11-41 key issue. The f-41 is responded differently.

no-response[bot] commented 3 years ago

This issue has been automatically closed because there has been no response to our request for more information from the original author. With only the information that is currently in the issue, we don't have enough information to take action. Please reach out if you have or find the answers we need so that we can investigate further.