RestComm / smscgateway

RestComm SMS Gateway (SMSC) to send/receive SMS from/to Operators Network (GSM)
http://www.restcomm.com/
GNU Affero General Public License v3.0
127 stars 111 forks source link

Restcomm SMSC keeps raising ActivityAlreadyExistsException when submit_sm request is sent #277

Closed MaabSaleeem closed 6 years ago

MaabSaleeem commented 6 years ago

I am using the latest version of Restcomm SMSC (smscgateway-7.3.153) (available here: https://github.com/RestComm/smscgateway/releases/tag/7.3.153). I used the binary version and not the source code.

I have got it up and running ad it communicates with Cassandra which is hosted on a different machine appropriately.

I have registered an ESME as a server and when I try to send a bind request, it succeeds and session is created. The problem occurs when I send the Submit_SM request. An ActivityAlreadyExists exception is raised and nothing else happens. I tried different simulators, even used an Android client to try to send a message but every time, the same exception occurs. I tried to debug the issue and was able to find out that the exception occurs when a new activity is about to be created but can't seem to find any more information.

It could be related to sequence numbers but I double checked and that doesn't seem to be the problem. I tried to change the tracing level of the server but I wasn't able to do so (Please guide me if anyone knows how to do it).

I am attaching a .pcap file that shows the packets I captured via Wireshark. All the request and response packets will be in there. I will also attach the server logs.

I couldn't find any help regarding this on the internet so if anyone of you can guide me here, I'd be very obliged. Please tag the developers if you know them. Feel free to ask for more information.

The wireshark capture file: https://drive.google.com/file/d/1gkxPAd4Gi6mr21ZdaptDEvlAnFoV0o0E/view?usp=sharing

The server startup logs: https://drive.google.com/file/d/1mjhn6NrT_Jv71BMqBQC8i6ac1Bn07PU7/view?usp=sharing

The exception logs: https://drive.google.com/file/d/1MxqmIGC1lN6IthDP1kV2HmdpSGOFkuRH/view

Here is the exception:

11:26:53,196 INFO [SmppServerConnector] (SmppManagement) New channel from [192.168.1.173:34034] 11:26:53,215 INFO [UnboundSmppSession] (SmppManagement.UnboundSession.192.168.1.173:34034) received PDU: (bind_transceiver: 0x00000025 0x00000009 0x00000000 0x00000001) (body: systemId [test5] password [test5] systemType [] interfaceVersion [0x34] addressRange (0x01 0x01 [6666])) (opts: ) 11:26:53,215 INFO [DefaultSmppServerHandler] (SmppManagement.UnboundSession.192.168.1.173:34034) Session created: Name=test5 SystemId=test5 11:26:55,504 ERROR [SmppSessionHandlerInterfaceImpl] (test5) Error while processing PduRequest=(submit_sm: 0x0000002F 0x00000004 0x00000000 0x00000002) (body: (serviceType [] sourceAddr [0x01 0x01 [6666]] destAddr [0x01 0x01 [5555]] esmCls [0x03] regDlvry [0x01] dcs [0x00] message [48656C6C6F21])) (opts: ) javax.slee.resource.ActivityAlreadyExistsException: RA:SmppServerRA:SmppTransactionHandle [smppSessionConfigurationName=test5, smppTransactionType=INCOMING, seqNumnber=2] at org.mobicents.slee.runtime.activity.ActivityContextFactoryImpl.createActivityContext(ActivityContextFactoryImpl.java:157) at org.mobicents.slee.runtime.activity.ActivityContextFactoryImpl.createActivityContext(ActivityContextFactoryImpl.java:57) at org.mobicents.slee.resource.SleeEndpointImpl._startActivity(SleeEndpointImpl.java:312) at org.mobicents.slee.resource.SleeEndpointStartActivityNotTransactedExecutor.execute(SleeEndpointStartActivityNotTransactedExecutor.java:63) at org.mobicents.slee.resource.SleeEndpointImpl.startActivity(SleeEndpointImpl.java:176) at org.restcomm.slee.resource.smpp.SmppServerResourceAdaptor.startNewSmppServerTransactionActivity(SmppServerResourceAdaptor.java:277) at org.restcomm.slee.resource.smpp.SmppSessionsImpl$SmppSessionHandlerImpl.firePduRequestReceived(SmppSessionsImpl.java:236) at com.cloudhopper.smpp.impl.DefaultSmppSession.firePduReceived(DefaultSmppSession.java:606) at com.cloudhopper.smpp.channel.SmppSessionWrapper.messageReceived(SmppSessionWrapper.java:52) at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:88) at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:296) at org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:462) at org.jboss.netty.handler.codec.frame.FrameDecoder.callDecode(FrameDecoder.java:443) at org.jboss.netty.handler.codec.frame.FrameDecoder.messageReceived(FrameDecoder.java:303) at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) at com.cloudhopper.smpp.channel.SmppSessionLogger.handleUpstream(SmppSessionLogger.java:104) at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) at com.cloudhopper.smpp.channel.SmppSessionThreadRenamer.handleUpstream(SmppSessionThreadRenamer.java:59) at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) at org.jboss.netty.channel.SimpleChannelUpstreamHandler.messageReceived(SimpleChannelUpstreamHandler.java:124) at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559) at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268) at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255) at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:318) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) at java.lang.Thread.run(Unknown Source)

MaabSaleeem commented 6 years ago

@vetss can you please let me know what the issue could be? I'd really appreciate any help.

faizann commented 6 years ago

This usually happens if you are connecting/disconnecting the ESME and sending the new SubmitSM with same sequenceNumbers as before the disconnection. So, my guess is that you are reusing sequence numbers on the same ESME.

On Tue, Jan 23, 2018 at 10:30 AM, MaabSaleeem notifications@github.com wrote:

I am using the latest version of Restcomm SMSC (smscgateway-7.3.153) (available here: https://github.com/RestComm/smscgateway/releases/tag/7.3. 153). I used the binary version and not the source code.

I have got it up and running ad it communicates with Cassandra which is hosted on a different machine appropriately.

I have registered an ESME as a server and when I try to send a bind request, it succeeds and session is created. The problem occurs when I send the Submit_SM request. An ActivityAlreadyExists exception is raised and nothing else happens. I tried different simulators, even used an Android client to try to send a message but every time, the same exception occurs. I tried to debug the issue and was able to find out that the exception occurs when a new activity is about to be created but can't seem to find any more information.

It could be related to sequence numbers but I double checked and that doesn't seem to be the problem. I tried to change the tracing level of the server but I wasn't able to do so (Please guide me if anyone knows how to do it).

I am attaching a .pcap file that shows the packets I captured via Wireshark. All the request and response packets will be in there. I will also attach the server logs.

I couldn't find any help regarding this on the internet so if anyone of you can guide me here, I'd be very obliged. Please tag the developers if you know them. Feel free to ask for more information.

The wireshark capture file: https://drive.google.com/file/d/1gkxPAd4Gi6mr21ZdaptDEvlAnFoV0 o0E/view?usp=sharing

The server startup logs: https://drive.google.com/file/d/1mjhn6NrT_Jv71BMqBQC8i6ac1Bn07PU7/view? usp=sharing

The exception logs: https://drive.google.com/file/d/1MxqmIGC1lN6IthDP1kV2HmdpSGOFkuRH/view

Here is the exception:

11:26:53,196 INFO [SmppServerConnector] (SmppManagement) New channel from [ 192.168.1.173:34034] 11:26:53,215 INFO [UnboundSmppSession] (SmppManagement.UnboundSession.192.168.1.173:34034) received PDU: (bind_transceiver: 0x00000025 0x00000009 0x00000000 0x00000001) (body: systemId [test5] password [test5] systemType [] interfaceVersion [0x34] addressRange (0x01 0x01 [6666])) (opts: ) 11:26:53,215 INFO [DefaultSmppServerHandler] (SmppManagement.UnboundSession.192.168.1.173:34034) Session created: Name=test5 SystemId=test5 11:26:55,504 ERROR [ SmppSessionHandlerInterfaceImpl] (test5) Error while processing PduRequest=(submit_sm: 0x0000002F 0x00000004 0x00000000 0x00000002) (body: (serviceType [] sourceAddr [0x01 0x01 [6666]] destAddr [0x01 0x01 [5555]] esmCls [0x03] regDlvry [0x01] dcs [0x00] message [48656C6C6F21])) (opts: ) javax.slee.resource.ActivityAlreadyExistsException: RA:SmppServerRA:SmppTransactionHandle [smppSessionConfigurationName=test5, smppTransactionType=INCOMING, seqNumnber=2] at org.mobicents.slee.runtime.activity. ActivityContextFactoryImpl.createActivityContext( ActivityContextFactoryImpl.java:157) at org.mobicents.slee.runtime. activity.ActivityContextFactoryImpl.createActivityContext( ActivityContextFactoryImpl.java:57) at org.mobicents.slee.resource. SleeEndpointImpl._startActivity(SleeEndpointImpl.java:312) at org.mobicents.slee.resource.SleeEndpointStartActivityNotTr ansactedExecutor.execute(SleeEndpointStartActivityNotTransactedExecutor.java:63) at org.mobicents.slee.resource.SleeEndpointImpl.startActivity(SleeEndpointImpl.java:176) at org.restcomm.slee.resource.smpp.SmppServerResourceAdaptor. startNewSmppServerTransactionActivity(SmppServerResourceAdaptor.java:277) at org.restcomm.slee.resource.smpp.SmppSessionsImpl$ SmppSessionHandlerImpl.firePduRequestReceived(SmppSessionsImpl.java:236) at com.cloudhopper.smpp.impl.DefaultSmppSession.firePduReceived(DefaultSmppSession.java:606) at com.cloudhopper.smpp.channel.SmppSessionWrapper.messageReceived(SmppSessionWrapper.java:52) at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:88) at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream( DefaultChannelPipeline.java:564) at org.jboss.netty.channel. DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream( DefaultChannelPipeline.java:791) at org.jboss.netty.channel. Channels.fireMessageReceived(Channels.java:296) at org.jboss.netty.handler.codec.frame.FrameDecoder. unfoldAndFireMessageReceived(FrameDecoder.java:462) at org.jboss.netty.handler.codec.frame.FrameDecoder.callDecode(FrameDecoder.java:443) at org.jboss.netty.handler.codec.frame.FrameDecoder. messageReceived(FrameDecoder.java:303) at org.jboss.netty.channel. SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream( DefaultChannelPipeline.java:564) at org.jboss.netty.channel. DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream( DefaultChannelPipeline.java:791) at com.cloudhopper.smpp.channel. SmppSessionLogger.handleUpstream(SmppSessionLogger.java:104) at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream( DefaultChannelPipeline.java:564) at org.jboss.netty.channel. DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream( DefaultChannelPipeline.java:791) at com.cloudhopper.smpp.channel. SmppSessionThreadRenamer.handleUpstream(SmppSessionThreadRenamer.java:59) at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream( DefaultChannelPipeline.java:564) at org.jboss.netty.channel. DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream( DefaultChannelPipeline.java:791) at org.jboss.netty.channel. SimpleChannelUpstreamHandler.messageReceived(SimpleChannelUpstreamHandler.java:124) at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream( SimpleChannelUpstreamHandler.java:70) at org.jboss.netty.channel. DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream( DefaultChannelPipeline.java:559) at org.jboss.netty.channel. Channels.fireMessageReceived(Channels.java:268) at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255) at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88) at org.jboss.netty.channel.socket.nio.AbstractNioWorker. process(AbstractNioWorker.java:108) at org.jboss.netty.channel.socket.nio. AbstractNioSelector.run(AbstractNioSelector.java:318) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) at org.jboss.netty.util.ThreadRenamingRunnable.run( ThreadRenamingRunnable.java:108) at org.jboss.netty.util.internal. DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) at java.lang.Thread.run(Unknown Source)

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/RestComm/smscgateway/issues/277, or mute the thread https://github.com/notifications/unsubscribe-auth/AA-f_JWa-TvaWpGQzpuc72rdCEJ63c2mks5tNaahgaJpZM4RpVZ1 .

MaabSaleeem commented 6 years ago

@faizann You are right. The reuse of old sequence numbers caused the issue. Is there any way this issue can be resolved? If a new session is created on basis of only system id and sequence number, won't this issue happen from time to time? This isn't unique enough Also can you please let me know how I can change tracing level of server?

faizann commented 6 years ago

Unforutnately there is no proper solution for this. You can on unbind close all transactions/activities forcefully from SessionHandler. Best is not to keep bind/unbind happening and keep SMPP connections open for long.

On Tue, 23 Jan 2018 at 11:46 MaabSaleeem notifications@github.com wrote:

@faizann https://github.com/faizann You are right. The reuse of old sequence numbers caused the issue. Is there any way this issue can be resolved? If a new session is created on basis of only system id and sequence number, won't this issue happen from time to time? This isn't unique enough Also can you please let me know how I can change tracing level of server?

— You are receiving this because you were mentioned.

Reply to this email directly, view it on GitHub https://github.com/RestComm/smscgateway/issues/277#issuecomment-359751897, or mute the thread https://github.com/notifications/unsubscribe-auth/AA-f_C7M9JnIq-KDV5X5M93uN06A0oAAks5tNbh4gaJpZM4RpVZ1 .

MaabSaleeem commented 6 years ago

@faizann How can I forcefully close all activities on unbind? Can I handle this from configuration?

faizann commented 6 years ago

There is no configuration for that. Doing that will require quite a bit of code and architectural change. For outbound packets on sessionDestroy the system fakes PduExpired event which causes all the activities to end. May be it can be a starting point to figure out how to do it for inbound SubmitSM that are still pending as a transaction. Ideally they should not last very long. Have a look at DefaultSmppServerHandler. I have not done any such fix myself as I don't get that problem due to long connections.

MaabSaleeem commented 6 years ago

Thanks a lot. Can you please tell me how I can change the tracing level of the server? I am still a beginner at this and have been unable to do so from configuration.

faizann commented 6 years ago

Hi Maab

http://documentation.telestax.com/core/jain_slee/JAIN_SLEE_User_Guide.html#_log4j_service Lets not discuss general issues on github. Use maillists if you can't find an answer by searching on Google.

On Wed, 24 Jan 2018 at 07:26 MaabSaleeem notifications@github.com wrote:

Thanks a lot. Can you please tell me how I can change the tracing level of the server? I am still a beginner at this and have been unable to do so from configuration.

— You are receiving this because you were mentioned.

Reply to this email directly, view it on GitHub https://github.com/RestComm/smscgateway/issues/277#issuecomment-360033278, or mute the thread https://github.com/notifications/unsubscribe-auth/AA-f_E9Kn91eyOUCdDWu-jCFAxXeeoViks5tNsz1gaJpZM4RpVZ1 .

gsaslis commented 6 years ago

Thanks a lot for stepping up @faizann !

As you mentioned, the best place for a discussion is the Restcomm mailing list.

Will close the issue for now, but @MaabSaleeem do feel free to reopen please if you think this is starting to look like some bug.