Closed Brokoth closed 2 years ago
@Brokoth I think the most likely reason for a timeout is that even though a response arrives, it cannot be mapped to the request due to a mismatching "MUX Key" which in your case should be derived from MTI (0800) and field 41 (34). If you can find out what the endpoint is returning this should provide some more clues.
BTW, your MUX Key configuration does not really make sense to me (there should be no MTI with value 0 as in your first line).
@tilln This is what the endpoint appears to be logging
[ 19 Jul 2021 11:52:10:550 ]| [ /IP ] Received Request Message [ 0800 0123456789 ] [ 19 Jul 2021 11:52:10:550 ]| org.jpos.iso.ISOException: null consumed=4 [ 19 Jul 2021 11:52:10:550 ]| at org.jpos.iso.ISOBasePackager.unpack(Unknown Source) [ 19 Jul 2021 11:52:10:550 ]| at org.jpos.iso.ISOMsg.unpack(Unknown Source) [ 19 Jul 2021 11:52:10:550 ]| at com.nls.soa.iso.ISOUtility.getEchoResponse(Unknown Source) [ 19 Jul 2021 11:52:10:550 ]| at com.nls.soa.iso.ISOSOAChannel$ISOSOARequestHandler.run(Unknown Source) [ 19 Jul 2021 11:52:10:550 ]| at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [ 19 Jul 2021 11:52:10:550 ]| at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [ 19 Jul 2021 11:52:10:550 ]| at java.lang.Thread.run(Unknown Source)
Might you know why this may result in a timeout?
@Brokoth Well, judging by the exception I suppose the endpoint did not actually sent a response back, so the timeout is genuine. Looks like your 0800 message was not able to be unpacked correctly. Given it failed at the first 4 bytes I would recommend looking at the channel configuration at the JMeter side and make sure it matches what the endpoint is expecting.
Does your 0800/0810 flow work without using JMeter+plugin? You can deploy a regular client and mux and use it to send your 0800. Once this succeeds use JMeter+plugin. If it doesn't, align your channel and packager. Make sure you have the same AsciiChannel at both ends and the packager is the same.
@tilln After changing my channel settings to this:
The endpoint appears to send a response back:
[ 21 Jul 2021 11:03:40:774 ]| Connection Request Received From [ /IP:PORT ] [ 21 Jul 2021 11:03:40:774 ]| Validating Incoming Address [ IP ] [ 21 Jul 2021 11:03:40:774 ]| Creating Thread To Process Request From [ /IP:PORT ] , Available Pool Size [ 3 ] [ 21 Jul 2021 11:03:40:774 ]| Thread Created To Process Request From [ /IP:PORT ], Available Pool Size After Creation [ 3 ] [ 21 Jul 2021 11:03:40:774 ]| [ /IP:PORT ] Receiving Request Message.... [ 21 Jul 2021 11:03:40:858 ]| [ /IP:PORT ] Reading Data... [ 21 Jul 2021 11:03:40:858 ]| [ /IP:PORT ] Received Request Message [ 080000200000008000000123456789 ] [ 21 Jul 2021 11:03:40:858 ]| [ /IP:PORT ] Sending Response ISO [ 08100020000002800000012345006789 ]
but the timeout still persists. Is this as a result of that mismatching "MUX Key" issue you referenced earlier?
@Brokoth I don't think so as the default MUX Key fields 11 and 41 (and MTI) are present and match up in request and response message. Perhaps you can confirm whether the JMeter plugin is actually receiving something as follows: Change you packager definition (JMeter side) to force an exception when unpacking which would then appear in the logs and confirm that some response was received, e.g. changing the length of field 39 to more bytes than the message contains.
@tilln Without even editing the packager file, this is the error jmeter is logging:
2021-07-22 10:23:50,378 ERROR n.c.b.j.i.Q2: (org.jpos.q2.iso.ChannelAdaptor) org.jpos.iso.IF_CHAR: Problem unpacking field 41 (java.lang.StringIndexOutOfBoundsException: String index out of range: 37) unpacking field=41, consumed=29 org.jpos.iso.ISOException: org.jpos.iso.IF_CHAR: Problem unpacking field 41 (java.lang.StringIndexOutOfBoundsException: String index out of range: 37) unpacking field=41, consumed=29
I think this means the plugin is receiving something but it is having trouble unpacking it right?
@Brokoth Looks like the field 41 (6789) is shorter than what the packager expects. Usually it would be 8 bytes.
@tilln Even after making it 8 bytes long the error still persists:
@Brokoth Hard to troubleshoot without seeing your packager file. Would you mind, as a minimum, posting how fields 0, 1, 11, 39, 41 are defined? The problem may be in some previous field, unpacking whatever bytes there are, only for the last field (41) to run out of bytes.
@tilln
Field 0:
<isofield id="0" length="4" name="Message Type Indicator" class="org.jpos.iso.IFA_NUMERIC"/>
Field 1:
<isofield id="1" length="16" name="Bitmap" class="org.jpos.iso.IFA_BITMAP"/>
Field 11:
<isofield id="11" length="6" name="Systems trace audit number" class="org.jpos.iso.IFA_NUMERIC"/>
Field 39:
<isofield id="39" length="3" name="Action code" class="org.jpos.iso.IFA_NUMERIC"/>
Field 41:
<isofield id="41" length="8" name="Card acceptor terminal identification" class="org.jpos.iso.IF_CHAR"/>
@Brokoth
This should probably be 2 bytes long: <isofield id="39" length="3"
This is your hex text unfortunately had to be extracted from the image
30 38 31 30 30 30 32 30 30 30 30 30 30 32 38 30
30 30 30 30 31 32 33 34 35 36 30 30 31 32 33 34
35 36 37 38
This is the ascii equivalent
08100020000028000001234560012345678
DE 0 : 30 38 31 30 : 0810 Bitmap : 30 30 32 30 30 30 30 30 30 32 38 30 30 30 30 30 : 002000002800000 DE 11 : 31 32 33 34 35 36 : 123456 DE 39 : 30 30 : 00 DE 41 : 31 32 33 34 35 36 37 38 : 12345678
As @tilln has mentioned , your field 39 packager should be 2 wide and not 3.
@tilln @chhil Firstly thank you for your patience and help. Changing field 39 length to 2 has finally fixed the problem. Are there any resources I can read so as to have an easier time debugging my future errors?
JPOS has tutorials and developer guides. http://jpos.org/doc/proguide-draft.pdf http://www.jpos.org/tutorials
JMeter has its own set.
And of course, the plugin is documented very well and easy to use if you come from the jpos background. Most problems will be jpos related, so its best to get jpos basics right.
@tilln @chhil I am also new to JMeter and ISO8583. I want to understand if the same configurations would work for a 0200 request. Are the default configurations same for a 0200 request?
The plugin @tilln has written, uses jpos for sending and receiving ISO8583 messages. ISO8583 messages come as flavors and are configured based on the packager. Packager is derived from the spec you would have. Jpos provides some out of the box packagers and if you are lucky you can just use them. If not you will have to write one yourself and for that you will need knowledge of JPOS). Once the packager is defined all standard ISO8583 message types (0100, 0101, 0110, 0120, 0121, 0130, 0200, 0201, 0210, 0220 etc. Sending messages over the wire will need channel configuration, you can use the standard ones provided or worst case scenario write one yourself. I haven't had to write one yet. Channels handle the communication and add additional headers that your messages may need.
Its best to familiarize yourself with ISo8583. You can configure the plugin and talk to any ISo8583 system. the plugin is based on jpos and its configurations are based on configuring jpos, so go through the jpos programmers guide, it will definitely help you.
I personally have worked with JPOS and ran into this jmeter plugin later, so using it was very simple.
@chhil @tilln. I've been trying to send a response for 0200 and getting a timeout also. Here is my request:
I'm going through the logs but not getting any meaningful error:
@johnkunari can you verify in the system you are testing that your request was received correctly and a response was generated?
If so, you can either turn on packager logging for the plugin (-J jmeter.iso8583.q2PackagerLogging=true
) or modify the packager to force an exception that gets logged in JMeter, in order to make sure that JMeter does in fact receive a response.
@johnkunari
If you still have this problem, please open a separate issue and provide debug logging output (-Lnz.co.breakpoint.jmeter.iso8583=DEBUG
)
@johnkunari
did you resolve your issue. are you getting the exact response in JMeter. If so please help me also
Dear team,
I am new to jmeter and ISO8583 too, and I try to follow guideline but I still error, could you help advice ?
error like this below:
2024-06-12 10:31:30,918 INFO o.a.j.e.StandardJMeterEngine: Running the test!
2024-06-12 10:31:30,918 INFO o.a.j.s.SampleEvent: List of sample_variables: []
2024-06-12 10:31:30,923 INFO n.c.b.j.i.Q2: (Q2.system) Q2 started, deployDir=D:\apache-jmeter-5.6.2\apache-jmeter-5.6.2\bin\deploy, environment=default
2024-06-12 10:31:30,945 ERROR n.c.b.j.i.Q2: (org.jpos.q2.iso.ChannelAdaptor) error starting service
2024-06-12 10:31:30,945 ERROR n.c.b.j.i.Q2: (org.jpos.q2.iso.ChannelAdaptor) org.jpos.core.ConfigurationException: Error reading D:/apache-jmeter-5.6.2/apache-jmeter-5.6.2/bin/ISO8583 Sampler.jmx (org.jpos.iso.ISOException: Error reading D:/apache-jmeter-5.6.2/apache-jmeter-5.6.2/bin/ISO8583 Sampler.jmx (org.xml.sax.SAXParseException; systemId: file:///D:/apache-jmeter-5.6.2/apache-jmeter-5.6.2/bin/ISO8583%20Sampler.jmx; lineNumber: 2; columnNumber: 16; Document is invalid: no grammar found.))
org.jpos.core.ConfigurationException: org.jpos.core.ConfigurationException: Error reading D:/apache-jmeter-5.6.2/apache-jmeter-5.6.2/bin/ISO8583 Sampler.jmx (org.jpos.iso.ISOException: Error reading D:/apache-jmeter-5.6.2/apache-jmeter-5.6.2/bin/ISO8583 Sampler.jmx (org.xml.sax.SAXParseException; systemId: file:///D:/apache-jmeter-5.6.2/apache-jmeter-5.6.2/bin/ISO8583%20Sampler.jmx; lineNumber: 2; columnNumber: 16; Document is invalid: no grammar found.))
at org.jpos.q2.QFactory.setConfiguration(QFactory.java:382) ~[jpos-2.1.8.jar:2.1.8]
at org.jpos.q2.iso.ChannelAdaptor.newChannel(ChannelAdaptor.java:202) ~[jpos-2.1.8.jar:2.1.8]
at org.jpos.q2.iso.ChannelAdaptor.initChannel(ChannelAdaptor.java:253) ~[jpos-2.1.8.jar:2.1.8]
at org.jpos.q2.iso.ChannelAdaptor.startService(ChannelAdaptor.java:76) [jpos-2.1.8.jar:2.1.8]
at org.jpos.q2.QBeanSupport.start(QBeanSupport.java:137) [jpos-2.1.8.jar:2.1.8]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_411]
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_411]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_411]
at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_411]
at sun.reflect.misc.Trampoline.invoke(Unknown Source) [?:1.8.0_411]
at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_411]
at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_411]
at sun.reflect.misc.MethodUtil.invoke(Unknown Source) [?:1.8.0_411]
at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(Unknown Source) [?:1.8.0_411]
at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(Unknown Source) [?:1.8.0_411]
at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(Unknown Source) [?:1.8.0_411]
at com.sun.jmx.mbeanserver.PerInterface.invoke(Unknown Source) [?:1.8.0_411]
at com.sun.jmx.mbeanserver.MBeanSupport.invoke(Unknown Source) [?:1.8.0_411]
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(Unknown Source) [?:1.8.0_411]
at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(Unknown Source) [?:1.8.0_411]
at org.jpos.q2.QFactory.startQBean(QFactory.java:176) [jpos-2.1.8.jar:2.1.8]
at nz.co.breakpoint.jmeter.iso8583.ISO8583Config.deployAndStart(ISO8583Config.java:364) [jmeter-iso8583-1.3.jar:?]
at nz.co.breakpoint.jmeter.iso8583.ISO8583Config.startChannelAdaptor(ISO8583Config.java:283) [jmeter-iso8583-1.3.jar:?]
at nz.co.breakpoint.jmeter.iso8583.ISO8583Config.testStarted(ISO8583Config.java:467) [jmeter-iso8583-1.3.jar:?]
at org.apache.jmeter.engine.StandardJMeterEngine.notifyTestListenersOfStart(StandardJMeterEngine.java:246) [ApacheJMeter_core.jar:5.6.2]
at org.apache.jmeter.engine.StandardJMeterEngine.run(StandardJMeterEngine.java:424) [ApacheJMeter_core.jar:5.6.2]
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) [?:1.8.0_411]
at java.util.concurrent.FutureTask.run(Unknown Source) [?:1.8.0_411]
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:1.8.0_411]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:1.8.0_411]
at java.lang.Thread.run(Unknown Source) [?:1.8.0_411]
2024-06-12 10:31:30,947 INFO o.a.j.g.u.JMeterMenuBar: setRunning(true, local)
2024-06-12 10:31:31,183 INFO o.a.j.e.StandardJMeterEngine: Starting ThreadGroup: 1 : Thread Group
2024-06-12 10:31:31,183 INFO o.a.j.e.StandardJMeterEngine: Starting 1 threads for group Thread Group.
2024-06-12 10:31:31,183 INFO o.a.j.e.StandardJMeterEngine: Thread will continue on error
2024-06-12 10:31:31,183 INFO o.a.j.t.ThreadGroup: Starting thread group... number=1 threads=1 ramp-up=30 delayedStart=false
2024-06-12 10:31:31,183 INFO o.a.j.t.ThreadGroup: Started thread group number 1
2024-06-12 10:31:31,183 INFO o.a.j.e.StandardJMeterEngine: All thread groups have been started
2024-06-12 10:31:31,184 INFO o.a.j.t.JMeterThread: Thread started: Thread Group 1-1
2024-06-12 10:31:31,185 ERROR n.c.b.j.i.ISO8583Config: Packager configuration error
org.xml.sax.SAXParseException: Document is invalid: no grammar found.
at org.apache.xerces.util.ErrorHandlerWrapper.createSAXParseException(Unknown Source) ~[xercesImpl-2.12.2.jar:?]
at org.apache.xerces.util.ErrorHandlerWrapper.error(Unknown Source) ~[xercesImpl-2.12.2.jar:?]
at org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source) ~[xercesImpl-2.12.2.jar:2.12.2]
at org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source) ~[xercesImpl-2.12.2.jar:2.12.2]
at org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source) ~[xercesImpl-2.12.2.jar:2.12.2]
at org.apache.xerces.impl.XMLNSDocumentScannerImpl.scanStartElement(Unknown Source) ~[xercesImpl-2.12.2.jar:2.12.2]
at org.apache.xerces.impl.XMLNSDocumentScannerImpl$NSContentDispatcher.scanRootElementHook(Unknown Source) ~[xercesImpl-2.12.2.jar:2.12.2]
at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl$FragmentContentDispatcher.dispatch(Unknown Source) ~[xercesImpl-2.12.2.jar:2.12.2]
at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown Source) ~[xercesImpl-2.12.2.jar:2.12.2]
at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source) ~[xercesImpl-2.12.2.jar:?]
at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source) ~[xercesImpl-2.12.2.jar:?]
at org.apache.xerces.parsers.XMLParser.parse(Unknown Source) ~[xercesImpl-2.12.2.jar:?]
at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source) ~[xercesImpl-2.12.2.jar:?]
at org.jpos.iso.packager.GenericPackager.readFile(GenericPackager.java:201) ~[jpos-2.1.8.jar:2.1.8]
at org.jpos.iso.packager.GenericPackager.
@Ranypho please open a separate Issue if you think this is a bug, or a Discussion for a question on how to use the plugin.
I am new to jmeter and ISO8583 and I am trying to test an endpoint by sending some ISO8583 messages to it. Unfortunately I am only getting a timeout response. I want to know if there are any configuration issues or whatever it may be. I pinged the IP and used telnet to confirm the endpoint is responsive. Below is my Connection Configuration:
Sampler:
and logs:
2021-07-16 10:42:51,786 DEBUG n.c.b.j.i.ISO8583Config: 'ISO8583 Connection Configuration' setting up QBeans jmeter-3d8171f0 2021-07-16 10:42:51,849 DEBUG n.c.b.j.i.ISO8583Config: Deployingjmeter-3d8171f0-send jmeter-3d8171f0-receive 10000 yes
2021-07-16 10:42:51,942 DEBUG n.c.b.j.i.ISO8583Config: Deploying jmeter-3d8171f0-receive jmeter-3d8171f0-send jmeter-3d8171f0-unhandled jmeter-3d8171f0.ready 42 41 11 41
2021-07-16 10:42:51,942 DEBUG n.c.b.j.i.Q2: (channel/HOST) [connect] Try 0 HOST:PORT
2021-07-16 10:42:51,958 INFO o.a.j.g.u.JMeterMenuBar: setRunning(true, local)
2021-07-16 10:42:52,036 INFO o.a.j.e.StandardJMeterEngine: Starting ThreadGroup: 1 : Thread Group
2021-07-16 10:42:52,036 INFO o.a.j.e.StandardJMeterEngine: Starting 1 threads for group Thread Group.
2021-07-16 10:42:52,036 INFO o.a.j.e.StandardJMeterEngine: Thread will continue on error
2021-07-16 10:42:52,036 INFO o.a.j.t.ThreadGroup: Starting thread group... number=1 threads=1 ramp-up=1 delayedStart=false
2021-07-16 10:42:52,052 INFO o.a.j.t.ThreadGroup: Started thread group number 1
2021-07-16 10:42:52,052 INFO o.a.j.e.StandardJMeterEngine: All thread groups have been started
2021-07-16 10:42:52,052 INFO o.a.j.t.JMeterThread: Thread started: Thread Group 1-1
2021-07-16 10:42:52,052 DEBUG n.c.b.j.i.ISO8583Sampler: Applying config 'ISO8583 Connection Configuration'
2021-07-16 10:42:52,052 DEBUG n.c.b.j.i.ISO8583Config: Creating packager from 'C:/Users/xxx/Downloads/jPOS/jPOS-2_1_6/jpos/src/dist/cfg/packager/test-generic-validating-packager.xml'
2021-07-16 10:42:52,067 DEBUG n.c.b.j.i.ISO8583Sampler: sampleStart
2021-07-16 10:42:52,067 DEBUG n.c.b.j.i.Q2: (channel/HOST:PORT) [send] Out: 0800 21 34
2021-07-16 10:42:58,079 DEBUG n.c.b.j.i.ISO8583Sampler: sampleEnd
2021-07-16 10:42:58,079 DEBUG n.c.b.j.i.ISO8583Sampler: Packed request '30383030303032303030303030303830303030303030303032313334202020202020'
2021-07-16 10:42:58,079 INFO o.a.j.t.JMeterThread: Thread is done: Thread Group 1-1
2021-07-16 10:42:58,079 INFO o.a.j.t.JMeterThread: Thread finished: Thread Group 1-1
2021-07-16 10:42:58,079 INFO o.a.j.e.StandardJMeterEngine: Notifying test listeners of end of test
2021-07-16 10:42:58,079 DEBUG n.c.b.j.i.ISO8583Config: Shutting down QBeans
2021-07-16 10:42:58,079 DEBUG n.c.b.j.i.ISO8583Config: Undeploying jmeter-3d8171f0-mux
2021-07-16 10:42:58,079 DEBUG n.c.b.j.i.ISO8583Config: Undeploying jmeter-3d8171f0-channel
2021-07-16 10:42:58,079 INFO n.c.b.j.i.Q2: (Q2.system) shutting down
2021-07-16 10:42:58,094 INFO n.c.b.j.i.Q2: (Q2.system) shutdown done
2021-07-16 10:42:58,094 INFO o.a.j.g.u.JMeterMenuBar: setRunning(false, local)