search

komuw / naz

naz is an async SMPP client.
https://komuw.github.io/naz/
MIT License
39 stars 12 forks source link

Interface version encoding #194

Closed rnesytov closed 4 years ago

rnesytov commented 4 years ago

Python 3.8.1 naz 0.7.7 MacOS 10.15.3

Hi. I tried to test my application, which uses naz over this simulator and got problems with bind stage.

With this example you can reproduce the problem:

import asyncio
import naz

loop = asyncio.get_event_loop()
broker = naz.broker.SimpleBroker(maxsize=1000)
cli = naz.Client(
    smsc_host="smscsim.melroselabs.com",
    smsc_port=2775,
    system_id="178895",
    password="ZDANDZ",
    broker=broker
)

# queue messages to send
for i in range(0, 4):
    print("submit_sm round:", i)

    msg = naz.protocol.SubmitSM(
            short_message="Hello World-{0}".format(str(i)),
            log_id="myid12345",
            source_addr="254722111111",
            destination_addr="12559498"
        )
    loop.run_until_complete(
       cli.send_message(msg)
)

try:
    # 1. connect to the SMSC host
    # 2. bind to the SMSC host
    # 3. send any queued messages to SMSC
    # 4. read any data from SMSC
    # 5. continually check the state of the SMSC
    tasks = asyncio.gather(
        cli.connect(),
        cli.tranceiver_bind(),
        cli.dequeue_messages(),
        cli.receive_data(),
        cli.enquire_link(),
    )
    loop.run_until_complete(tasks)
except Exception as e:
    print("exception occured. error={0}".format(str(e)))
finally:
    loop.run_until_complete(cli.unbind())
    loop.stop()

Here logs

 ~/zvooq/ZSMPP  .venv   master ● ?  python -m zsmpp.test                                                                                          ✓ 
submit_sm round: 0
{"timestamp": "2020-02-13 19:21:10,032", "event": "naz.Client.send_message", "stage": "start", "log_id": "myid12345", "smpp_command": "submit_sm", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:10,033", "event": "naz.Client.send_message", "stage": "end", "log_id": "myid12345", "smpp_command": "submit_sm", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
submit_sm round: 1
{"timestamp": "2020-02-13 19:21:10,033", "event": "naz.Client.send_message", "stage": "start", "log_id": "myid12345", "smpp_command": "submit_sm", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:10,033", "event": "naz.Client.send_message", "stage": "end", "log_id": "myid12345", "smpp_command": "submit_sm", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
submit_sm round: 2
{"timestamp": "2020-02-13 19:21:10,033", "event": "naz.Client.send_message", "stage": "start", "log_id": "myid12345", "smpp_command": "submit_sm", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:10,033", "event": "naz.Client.send_message", "stage": "end", "log_id": "myid12345", "smpp_command": "submit_sm", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
submit_sm round: 3
{"timestamp": "2020-02-13 19:21:10,034", "event": "naz.Client.send_message", "stage": "start", "log_id": "myid12345", "smpp_command": "submit_sm", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:10,034", "event": "naz.Client.send_message", "stage": "end", "log_id": "myid12345", "smpp_command": "submit_sm", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:10,034", "event": "naz.Client.connect", "stage": "start", "log_id": "mywyh6tde632xev0l", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:10,034", "event": "naz.Client.tranceiver_bind", "stage": "start", "log_id": "9elhcr2mn1lb1o9ut", "smpp_command": "bind_transceiver", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:10,034", "event": "naz.Client.send_data", "stage": "start", "smpp_command": "bind_transceiver", "log_id": "9elhcr2mn1lb1o9ut", "msg": "\u0000\u0000\u0000,\u0000\u0000\u0000\t\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0002178895\u0000{REDACTED}\u0000\u0000\u0000\u0000\u0000\"\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000", "connection_lost": true, "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:10,034", "event": "naz.Client.send_data", "stage": "end", "smpp_command": "bind_transceiver", "log_id": "9elhcr2mn1lb1o9ut", "msg": "\u0000\u0000\u0000,\u0000\u0000\u0000\t\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0002178895\u0000{REDACTED}\u0000\u0000\u0000\u0000\u0000\"\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000", "current_session_state": "CLOSED", "error": "smpp_command `bind_transceiver` cannot be sent to SMSC when the client session state is `CLOSED`", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
NoneType: None
{"timestamp": "2020-02-13 19:21:10,040", "event": "naz.Client.tranceiver_bind", "stage": "end", "log_id": "9elhcr2mn1lb1o9ut", "smpp_command": "bind_transceiver", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:10,040", "event": "naz.Client.dequeue_messages", "stage": "start", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:10,040", "event": "naz.Client.dequeue_messages", "stage": "start", "current_session_state": "CLOSED", "state": "awaiting naz to change session state to `BOUND_TRX`. sleeping for 30.00 seconds", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:10,040", "event": "naz.Client.receive_data", "stage": "start", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:10,040", "event": "naz.Client.receive_data", "stage": "end", "state": "naz is yet to bind to SMSC. sleeping for 30.00 seconds", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:10,195", "event": "naz.Client.connect", "stage": "end", "log_id": "mywyh6tde632xev0l", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
^[[3{"timestamp": "2020-02-13 19:21:40,042", "event": "naz.Client.dequeue_messages", "stage": "start", "current_session_state": "OPEN", "state": "awaiting naz to change session state to `BOUND_TRX`. sleeping for 30.00 seconds", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:40,042", "event": "naz.Client.re_establish_conn_bind", "stage": "start", "smpp_command": "", "log_id": "", "connection_lost": false, "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:40,042", "event": "naz.Client.connect", "stage": "start", "log_id": "yc46202hgd4rtij6d", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:40,113", "event": "naz.Client.connect", "stage": "end", "log_id": "yc46202hgd4rtij6d", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:40,113", "event": "naz.Client.tranceiver_bind", "stage": "start", "log_id": "ms2vf2u2kvils8som", "smpp_command": "bind_transceiver", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:40,113", "event": "naz.Client.send_data", "stage": "start", "smpp_command": "bind_transceiver", "log_id": "ms2vf2u2kvils8som", "msg": "\u0000\u0000\u0000,\u0000\u0000\u0000\t\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0003178895\u0000{REDACTED}\u0000\u0000\u0000\u0000\u0000\"\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000", "connection_lost": false, "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:40,114", "event": "naz.Client.send_data", "stage": "end", "smpp_command": "bind_transceiver", "log_id": "ms2vf2u2kvils8som", "msg": "\u0000\u0000\u0000,\u0000\u0000\u0000\t\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0003178895\u0000{REDACTED}\u0000\u0000\u0000\u0000\u0000\"\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:40,114", "event": "naz.Client.tranceiver_bind", "stage": "end", "log_id": "ms2vf2u2kvils8som", "smpp_command": "bind_transceiver", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:40,114", "event": "naz.Client.re_establish_conn_bind", "stage": "end", "smpp_command": "", "log_id": "", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:40,114", "event": "naz.Client.receive_data", "stage": "start", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
^R
^[[{"timestamp": "2020-02-13 19:21:40,350", "event": "naz.Client.command_handlers", "stage": "start", "smpp_command": "bind_transceiver_resp", "log_id": "ms2vf2u2kvils8som", "command_status": 13, "state": "Bind Failed", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
NoneType: None
{"timestamp": "2020-02-13 19:21:40,351", "event": "naz.Client.receive_data", "stage": "end", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}
{"timestamp": "2020-02-13 19:21:40,351", "event": "naz.Client.receive_data", "stage": "start", "smsc_host": "smscsim.melroselabs.com", "system_id": "178895", "client_id": "OZAXH1X2V0E6I0JWS", "pid": 48254}

Via Wireshark I found that version in the packet is zero image

Now let's look at this code https://github.com/komuw/naz/blob/895a269273bb5d445c75b63098375bd9bacccf7d/naz/client.py#L631 ">L" means that will be used 4 octets, but SMPP v3.4 documentation says that interface_version should be size of 1 octet (also as addr_ton andaddr_npi). So, I think, here should be struct.pack(">B", self.interface_version).

But it doesn't help. After that fix, I got version 2.2 in the BindTranceiver message. image

Looks like default interface_version should be 0x34

>>> import struct
>>> struct.pack(">B", 34).hex()
'22'
>>> struct.pack(">B", 0x34).hex()
'34'
komuw commented 4 years ago

thanks. Will look into it.

komuw commented 4 years ago

Note to self;

  1. https://docs.python.org/3.7/library/struct.html#format-characters
komuw commented 4 years ago

@profx5 hi, would you mind trying out this beta version: https://pypi.org/project/naz/0.7.8b0/
and letting me know if there are any issues with it.

rnesytov commented 4 years ago

@komuw, I tested this version, and it works well, thank you!