Tsung load testing not able to send message ejabberd server

665 views Asked by At

I am new to this tsung load testing framework, since last one week i have been exploring this tool to load test my ejabberd server till now i am able to register some 200 users at one go that is awesome, i am able to generate report Graphs (right now it is blank all over).

My problem is I am not able to send message from the sendmessage.xml file to my any other user through I am new to this tsung load testing framework, since last one week i have been exploring this tool to load test my ejabberd server till now i am able to register some 200 users at one go that is awesome, i am able to generate report Graphs (right now it is blank all over).

My problem is I am not able to send message from the sendmessage.xml file to my any other user through my ejabberd instance here is my sendmessage.xml

    <?xml version="1.0" encoding="ISO-8859-1"?>
 <!DOCTYPE tsung SYSTEM "/usr/share/tsung/tsung-1.0.dtd" [] >
 <tsung loglevel="info" backend="json">
  <clients>
    <client host="localhost" use_controller_vm="true"/>
  </clients>
  <servers>
    <server host="*.*.*.*" port="5222" type="tcp"/>
  </servers>
  <load duration="12" unit="minute">
    <arrivalphase phase="1" duration="12" unit="minute">
         <users maxnumber="100" interarrival="1" unit="second"></users>
    </arrivalphase>
  </load>
  <options>
    <option type="ts_jabber" name="global_number" value="5"></option>
    <option type="ts_jabber" name="userid_max" value="200000" />
    <option type="ts_jabber" name="domain" value="hostname.com" />
    <option type="ts_jabber" name="username" value="andupandu" />
    <option type="ts_jabber" name="passwd" value="password" />
 </options>
 <sessions>
    <session probability="100" name="xmpp-connection" type="ts_jabber">
    <request> <jabber type="connect" ack="local"></jabber> </request>
    <thinktime value="2"></thinktime>
    <request><jabber type="starttls" ack="bidi_ack" />
    </request>
    <thinktime value="5"></thinktime>
    <transaction name="authenticate">
       <request> <jabber type="auth_sasl_anonymous" ack="local"></jabber> </request>
       <request> <jabber type="connect" ack="local"></jabber> </request>
       <request> <jabber type="auth_sasl_bind" ack="local" ></jabber></request>
       <request> <jabber type="auth_sasl_session" ack="local" ></jabber></request>
       <request> <jabber type="presence:initial" ack="no_ack"/> </request>
    </transaction>
    <thinktime value="5"></thinktime>
    <transaction name="online">
     <request> <jabber type="chat" ack="no_ack" size="4000" destination="online"/></request>
   </transaction>
     <transaction name="close">
        <request> <jabber type="close" ack="local"></jabber> </request>
    </transaction>
    </session>
</sessions>
</tsung>

While running this script i was going my ejabberd.log file this is coming

2016-12-19 11:02:43.553 [info] <0.606.0>@ejabberd_listener:accept:333 (#Port<0.30840>) Accepted connection 223.30.185.182:46844 -> 122.166.14.59:5222
2016-12-19 11:02:43.772 [info] <0.606.0>@ejabberd_listener:accept:333 (#Port<0.30841>) Accepted connection 223.30.185.182:48205 -> 122.166.14.59:5222
2016-12-19 11:02:44.266 [info] <0.606.0>@ejabberd_listener:accept:333 (#Port<0.30842>) Accepted connection 223.30.185.182:48358 -> 122.166.14.59:5222
2016-12-19 11:02:45.530 [info] <0.606.0>@ejabberd_listener:accept:333 (#Port<0.30843>) Accepted connection 223.30.185.182:46427 -> 122.166.14.59:5222
2016-12-19 11:02:45.689 [info] <0.606.0>@ejabberd_listener:accept:333 (#Port<0.30844>) Accepted connection 223.30.185.182:48789 -> 122.166.14.59:5222
2016-12-19 11:02:46.872 [info] <0.606.0>@ejabberd_listener:accept:333 (#Port<0.30845>) Accepted connection 223.30.185.182:34836 -> 122.166.14.59:5222
2016-12-19 11:02:48.092 [info] <0.606.0>@ejabberd_listener:accept:333 (#Port<0.30846>) Accepted connection 223.30.185.182:33801 -> 122.166.14.59:5222
2016-12-19 11:02:49.144 [info] <0.606.0>@ejabberd_listener:accept:333 (#Port<0.30847>) Accepted connection 223.30.185.182:33990 -> 122.166.14.59:5222
2016-12-19 11:02:50.479 [info] <0.606.0>@ejabberd_listener:accept:333 (#Port<0.30848>) Accepted connection 223.30.185.182:50522 -> 122.166.14.59:5222
2016-12-19 11:02:51.676 [info] <0.606.0>@ejabberd_listener:accept:333 (#Port<0.30849>) Accepted connection 223.30.185.182:40768 -> 122.166.14.59:5222
2016-12-19 11:02:52.925 [info] <0.606.0>@ejabberd_listener:accept:333 (#Port<0.30850>) Accepted connection 223.30.185.182:57973 -> 122.166.14.59:5222
2016-12-19 11:02:53.759 [info] <0.606.0>@ejabberd_listener:accept:333 (#Port<0.30851>) Accepted connection 223.30.185.182:41619 -> 122.166.14.59:5222
2016-12-19 11:02:54.371 [info] <0.606.0>@ejabberd_listener:accept:333 (#Port<0.30852>) Accepted connection 223.30.185.182:42115 -> 122.166.14.59:5222
... and similar 

the problem is session is not getting created

and folowing tsung.log i am getting

{
 "stats": [
 {"timestamp": 1482142630,  "samples": []},
 {"timestamp": 1482142640,  "samples": [   {"name": "users", "value": 3, "max": 3}, {"name": "cpu", "hostname": "neureol", "value": 1, "mean": 5.301845187701585,"stddev": 0,"max": 5.301845187701585,"min": 5.301845187701585 ,"global_mean": 0 ,"global_count": 0}, {"name": "load", "hostname": "neureol", "value": 1, "mean": 0.37109375,"stddev": 0,"max": 0.37109375,"min": 0.37109375 ,"global_mean": 0 ,"global_count": 0}, {"name": "freemem", "hostname": "neureol", "value": 1, "mean": 4278.2265625,"stddev": 0,"max": 4278.2265625,"min": 4278.2265625 ,"global_mean": 0 ,"global_count": 0}, {"name": "users_count", "value": 3, "total": 3}, {"name": "finish_users_count", "value": 0, "total": 0}, {"name": "request", "value": 3, "mean": 264.84033203125,"stddev": 88.15162068742659,"max":  389.04296875,"min": 193.447021484375 ,"global_mean": 0 ,"global_count": 0}, {"name": "connect", "value": 3, "mean": 125.679931640625,"stddev": 42.371197826714514,"max":  185.3427734375,"min": 91.028076171875 ,"global_mean": 0 ,"global_count": 0}, {"name": "page", "value": 3, "mean": 264.84033203125,"stddev": 88.15162068742659,"max":  389.04296875,"min": 193.447021484375 ,"global_mean": 0 ,"global_count": 0}, {"name": "size_rcv", "value": 2024, "total": 2024}, {"name": "size_sent", "value": 501, "total": 501}, {"name": "connected", "value": 3, "max": 3}]},
 {"timestamp": 1482142650,  "samples": [   {"name": "users", "value": 7, "max": 7}, {"name": "cpu", "hostname": "neureol", "value": 1, "mean": 7.1357035553329995,"stddev": 0.0,"max": 7.1357035553329995,"min": 5.301845187701585 ,"global_mean": 5.301845187701585 ,"global_count": 1}, {"name": "load", "hostname": "neureol", "value": 1, "mean": 0.30859375,"stddev": 0.0,"max": 0.37109375,"min": 0.30859375 ,"global_mean": 0.37109375 ,"global_count": 1}, {"name": "freemem", "hostname": "neureol", "value": 1, "mean": 4275.30078125,"stddev": 0.0,"max": 4278.2265625,"min": 4275.30078125 ,"global_mean": 4278.2265625 ,"global_count": 1}, {"name": "users_count", "value": 4, "total": 7}, {"name": "finish_users_count", "value": 0, "total": 0}, {"name": "request", "value": 4, "mean": 522.1024780273438,"stddev": 425.6234764859712,"max":  1257.77099609375,"min": 193.447021484375 ,"global_mean": 264.84033203125 ,"global_count": 3}, {"name": "connect", "value": 4, "mean": 398.53875732421875,"stddev": 438.4391252124725,"max":  1156.155029296875,"min": 91.028076171875 ,"global_mean": 125.679931640625 ,"global_count": 3}, {"name": "page", "value": 4, "mean": 522.1024780273438,"stddev": 425.6234764859712,"max":  1257.77099609375,"min": 193.447021484375 ,"global_mean": 264.84033203125 ,"global_count": 3}, {"name": "size_rcv", "value": 2784, "total": 4808}, {"name": "size_sent", "value": 753, "total": 1254}, {"name": "connected", "value": 4, "max": 7}]}]}

If you see the tsung.log which is showing similar to {"name": "connected", "value": 3, "max": 3} how it is coming since there is no any log present there on ejbbered side .

After running perl script i am getting totally blank report with graph.

Here is my ijabberd.yml is :-

loglevel: 4

log_rotate_size: 10485760
log_rotate_date: ""
log_rotate_count: 1

log_rate_limit: 100

hosts:
  - "something.com"
  - "122.166.14.59"
  - "demo.something.com"

listen:
  - 
    port: 5222
    module: ejabberd_c2s
    certfile: "/opt/ejabberd-16.06/conf/server.pem"
    starttls: true
    ## To enforce TLS encryption for client connections,
    ## use this instead of the "starttls" option:
    ## starttls_required: true
    ##
    ## Custom OpenSSL options
    ##
    protocol_options:
      - "no_sslv3"
    ##   - "no_tlsv1"
    max_stanza_size: 65536
    shaper: c2s_shaper
    access: c2s
    resend_on_timeout: true
  - 
    port: 5269
    module: ejabberd_s2s_in
    max_stanza_size: 131072
    shaper: s2s_shaper

  - 
    port: 5280
    module: ejabberd_http
    request_handlers:
      "/websocket": ejabberd_http_ws
    ##  "/pub/archive": mod_http_fileserver
    web_admin: true
    http_bind: true
    ## register: true
    captcha: false




auth_method: internal


auth_method: anonymous
anonymous_protocol: both
allow_multiple_connections: true
host_config:
 "something.com":
  odbc_type: mysql
  odbc_server: "localhost"
  odbc_database: "chatdb"
  odbc_username: "siteuser"
  odbc_password: "site!@#$"
  auth_method: [odbc]

shaper:
  ##
  ## The "normal" shaper limits traffic speed to 1000 B/s
  ##
  normal: 1000

  ##
  ## The "fast" shaper limits traffic speed to 50000 B/s
  ##
  fast: 500000000 
max_fsm_queue: 1000

shaper_rules:
  ## Maximum number of simultaneous sessions allowed for a single user:
  max_user_sessions: 10
  ## Maximum number of offline messages that users can have:
  max_user_offline_messages:
    - allow: all
  ## For C2S connections, all users except admins use the "normal" shaper
  c2s_shaper:
    - none: admin
    - fast
  ## All S2S connections use the "fast" shaper
  s2s_shaper: fast
access_rules:
  ## This rule allows access only for local users:
  local:
    - allow: local
  ## Only non-blocked users can use c2s connections:
  c2s:
    - deny: blocked
    - allow
  ## Only admins can send announcement messages:
  announce:
    - allow: admin
  ## Only admins can use the configuration interface:
  configure:
    - allow: admin
  ## Only accounts of the local ejabberd server can create rooms:
  muc_create:
    - allow: local
  ## Only accounts on the local ejabberd server can create Pubsub nodes:
  pubsub_createnode:
    - allow: local
  ## In-band registration allows registration of any possible username.
  ## To disable in-band registration, replace 'allow' with 'deny'.
  register:
    - allow
  ## Only allow to register from localhost
  trusted_network:
    - allow: all

registration_timeout: infinity

modules:
  mod_adhoc: {}
  mod_admin_extra: {}
  mod_announce: # recommends mod_adhoc
    access: announce
  mod_blocking: {} # requires mod_privacy
  mod_caps: {}
  mod_carboncopy: {}
  mod_client_state: {}
  mod_configure: {} # requires mod_adhoc
  mod_disco: {}
  ## mod_echo: {}
  mod_http_bind: {}
  mod_last: {}
  mod_muc:
    access:
      - allow
    access_admin:
      - allow: admin
    access_create: muc_create
    access_persistent: muc_create
  mod_muc_admin: {}
  ## mod_muc_log: {}
  ## mod_multicast: {}
  mod_offline:
    access_max_user_messages: max_user_offline_messages
  mod_ping: 
    send_pings: true
    ping_interval: 60
    ping_ack_timout: 32
    timeout_action: kill
  mod_privacy: {}
  mod_private: {}
  mod_pubsub:
    access_createnode: pubsub_createnode
    ## reduces resource comsumption, but XEP incompliant
    ignore_pep_from_offline: true
    ## XEP compliant, but increases resource comsumption
    ## ignore_pep_from_offline: false
    last_item_cache: false
    plugins:
      - "flat"
      - "hometree"
      - "pep" # pep requires mod_caps
  mod_register:
    welcome_message:
      subject: "Welcome!"
      body: |-
        Hi.
        Welcome to this XMPP server.
    access: register
  mod_roster: {}
  mod_shared_roster: {}
  mod_vcard:
    search: false
  mod_version: {}

allow_contrib_modules: true

After changing the ejabber log to 5 here is the ejabber.logs are :

    2016-12-20 12:35:09.694 [info] <0.3540.1>@ejabberd_listener:accept:333 (#Port<0.123804>) Accepted connection 223.30.185.182:44998 -> *.*.*.*:5222
2016-12-20 12:35:09.696 [debug] <0.8478.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<?xml version='1.0'?><stream:stream  id='1' to='something.com' xmlns='jabber:client' version='1.0' xmlns:stream='http://etherx.jabber.org/streams'>">>
2016-12-20 12:35:09.696 [debug] <0.8479.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='12153081287775773739' from='something.com' version='1.0' xml:lang='en'>">>
2016-12-20 12:35:09.697 [debug] <0.8479.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<stream:features><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='Xe/lYmivnmPRh4GEsNf6U13V4G8='/><register xmlns='http://jabber.org/features/iq-register'/><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism><mechanism>DIGEST-MD5</mechanism><mechanism>X-OAUTH2</mechanism><mechanism>SCRAM-SHA-1</mechanism></mechanisms></stream:features>">>
2016-12-20 12:35:10.043 [info] <0.3540.1>@ejabberd_listener:accept:333 (#Port<0.123801>) Accepted connection 223.30.185.182:36296 -> *.*.*.*:5222
2016-12-20 12:35:10.044 [debug] <0.8480.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<?xml version='1.0'?><stream:stream  id='2' to='something.com' xmlns='jabber:client' version='1.0' xmlns:stream='http://etherx.jabber.org/streams'>">>
2016-12-20 12:35:10.044 [debug] <0.8481.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='3424930239190161372' from='something.com' version='1.0' xml:lang='en'>">>
2016-12-20 12:35:10.045 [debug] <0.8481.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<stream:features><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='Xe/lYmivnmPRh4GEsNf6U13V4G8='/><register xmlns='http://jabber.org/features/iq-register'/><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism><mechanism>DIGEST-MD5</mechanism><mechanism>X-OAUTH2</mechanism><mechanism>SCRAM-SHA-1</mechanism></mechanisms></stream:features>">>
2016-12-20 12:35:11.173 [info] <0.3540.1>@ejabberd_listener:accept:333 (#Port<0.123807>) Accepted connection 223.30.185.182:35101 -> *.*.*.*:5222
2016-12-20 12:35:11.175 [debug] <0.8482.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<?xml version='1.0'?><stream:stream  id='3' to='something.com' xmlns='jabber:client' version='1.0' xmlns:stream='http://etherx.jabber.org/streams'>">>
2016-12-20 12:35:11.175 [debug] <0.8483.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='10270498772362791845' from='something.com' version='1.0' xml:lang='en'>">>
2016-12-20 12:35:11.176 [debug] <0.8483.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<stream:features><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='Xe/lYmivnmPRh4GEsNf6U13V4G8='/><register xmlns='http://jabber.org/features/iq-register'/><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism><mechanism>DIGEST-MD5</mechanism><mechanism>X-OAUTH2</mechanism><mechanism>SCRAM-SHA-1</mechanism></mechanisms></stream:features>">>
2016-12-20 12:35:11.872 [debug] <0.8478.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<starttls xmlns=\"urn:ietf:params:xml:ns:xmpp-tls\"/>">>
2016-12-20 12:35:11.872 [debug] <0.8478.1>@shaper:update:120 State: {maxrate,500000000,0.0,1482217509697017}, Size=51
M=5.1e-5, I=2175.696
2016-12-20 12:35:11.873 [debug] <0.8478.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<>>
2016-12-20 12:35:11.873 [debug] <0.8478.1>@shaper:update:120 State: {maxrate,500000000,11.719617122406575,1482217511872856}, Size=0
M=0.0, I=0.328
2016-12-20 12:35:12.157 [debug] <0.8480.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<starttls xmlns=\"urn:ietf:params:xml:ns:xmpp-tls\"/>">>
2016-12-20 12:35:12.157 [debug] <0.8480.1>@shaper:update:120 State: {maxrate,500000000,0.0,1482217510044454}, Size=51
M=5.1e-5, I=2113.04
2016-12-20 12:35:12.157 [debug] <0.8480.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<>>
2016-12-20 12:35:12.158 [debug] <0.8480.1>@shaper:update:120 State: {maxrate,500000000,12.067047354406341,1482217512157647}, Size=0
M=0.0, I=0.311
2016-12-20 12:35:13.303 [debug] <0.8482.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<starttls xmlns=\"urn:ietf:params:xml:ns:xmpp-tls\"/>">>
2016-12-20 12:35:13.303 [debug] <0.8482.1>@shaper:update:120 State: {maxrate,500000000,0.0,1482217511175417}, Size=51
M=5.1e-5, I=2128.331
2016-12-20 12:35:13.304 [debug] <0.8482.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<>>
2016-12-20 12:35:13.304 [debug] <0.8482.1>@shaper:update:120 State: {maxrate,500000000,11.980431023020751,1482217513303888}, Size=0
M=0.0, I=0.368
2016-12-20 12:35:15.202 [info] <0.3540.1>@ejabberd_listener:accept:333 (#Port<0.123812>) Accepted connection 223.30.185.182:49986 -> *.*.*.*:5222
2016-12-20 12:35:15.203 [debug] <0.8484.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<?xml version='1.0'?><stream:stream  id='4' to='something.com' xmlns='jabber:client' version='1.0' xmlns:stream='http://etherx.jabber.org/streams'>">>
2016-12-20 12:35:15.203 [debug] <0.8485.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='6574869083255218624' from='something.com' version='1.0' xml:lang='en'>">>
2016-12-20 12:35:15.204 [debug] <0.8485.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<stream:features><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='Xe/lYmivnmPRh4GEsNf6U13V4G8='/><register xmlns='http://jabber.org/features/iq-register'/><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism><mechanism>DIGEST-MD5</mechanism><mechanism>X-OAUTH2</mechanism><mechanism>SCRAM-SHA-1</mechanism></mechanisms></stream:features>">>
2016-12-20 12:35:15.504 [info] <0.3540.1>@ejabberd_listener:accept:333 (#Port<0.123810>) Accepted connection 223.30.185.182:41718 -> *.*.*.*:5222
2016-12-20 12:35:15.505 [debug] <0.8486.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<?xml version='1.0'?><stream:stream  id='5' to='something.com' xmlns='jabber:client' version='1.0' xmlns:stream='http://etherx.jabber.org/streams'>">>
2016-12-20 12:35:15.506 [debug] <0.8487.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='11910276457718456980' from='something.com' version='1.0' xml:lang='en'>">>
2016-12-20 12:35:15.507 [debug] <0.8487.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<stream:features><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='Xe/lYmivnmPRh4GEsNf6U13V4G8='/><register xmlns='http://jabber.org/features/iq-register'/><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism><mechanism>DIGEST-MD5</mechanism><mechanism>X-OAUTH2</mechanism><mechanism>SCRAM-SHA-1</mechanism></mechanisms></stream:features>">>
2016-12-20 12:35:16.979 [info] <0.3540.1>@ejabberd_listener:accept:333 (#Port<0.123799>) Accepted connection 223.30.185.182:57791 -> *.*.*.*:5222
2016-12-20 12:35:16.980 [debug] <0.8488.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<?xml version='1.0'?><stream:stream  id='6' to='something.com' xmlns='jabber:client' version='1.0' xmlns:stream='http://etherx.jabber.org/streams'>">>
2016-12-20 12:35:16.980 [debug] <0.8489.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='16257359711038503484' from='something.com' version='1.0' xml:lang='en'>">>
2016-12-20 12:35:16.981 [debug] <0.8489.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<stream:features><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='Xe/lYmivnmPRh4GEsNf6U13V4G8='/><register xmlns='http://jabber.org/features/iq-register'/><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism><mechanism>DIGEST-MD5</mechanism><mechanism>X-OAUTH2</mechanism><mechanism>SCRAM-SHA-1</mechanism></mechanisms></stream:features>">>
2016-12-20 12:35:17.486 [debug] <0.8484.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<starttls xmlns=\"urn:ietf:params:xml:ns:xmpp-tls\"/>">>
2016-12-20 12:35:17.487 [debug] <0.8484.1>@shaper:update:120 State: {maxrate,500000000,0.0,1482217515203642}, Size=51
M=5.1e-5, I=2283.43
2016-12-20 12:35:17.487 [debug] <0.8484.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<>>
2016-12-20 12:35:17.487 [debug] <0.8484.1>@shaper:update:120 State: {maxrate,500000000,11.166760014941563,1482217517487205}, Size=0
M=0.0, I=0.271
2016-12-20 12:35:17.756 [debug] <0.8486.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<starttls xmlns=\"urn:ietf:params:xml:ns:xmpp-tls\"/>">>
2016-12-20 12:35:17.756 [debug] <0.8486.1>@shaper:update:120 State: {maxrate,500000000,0.0,1482217515505921}, Size=51
M=5.1e-5, I=2250.965
2016-12-20 12:35:17.757 [debug] <0.8486.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<>>
2016-12-20 12:35:17.757 [debug] <0.8486.1>@shaper:update:120 State: {maxrate,500000000,11.32786071795537,1482217517757008}, Size=0
M=0.0, I=0.314
2016-12-20 12:35:17.793 [info] <0.3540.1>@ejabberd_listener:accept:333 (#Port<0.123817>) Accepted connection 223.30.185.182:42577 -> *.*.*.*:5222
2016-12-20 12:35:17.803 [debug] <0.8490.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<?xml version='1.0'?><stream:stream  id='7' to='something.com' xmlns='jabber:client' version='1.0' xmlns:stream='http://etherx.jabber.org/streams'>">>
2016-12-20 12:35:17.803 [debug] <0.8491.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='3919444622270218959' from='something.com' version='1.0' xml:lang='en'>">>
2016-12-20 12:35:17.804 [debug] <0.8491.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<stream:features><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='Xe/lYmivnmPRh4GEsNf6U13V4G8='/><register xmlns='http://jabber.org/features/iq-register'/><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism><mechanism>DIGEST-MD5</mechanism><mechanism>X-OAUTH2</mechanism><mechanism>SCRAM-SHA-1</mechanism></mechanisms></stream:features>">>
2016-12-20 12:35:18.762 [info] <0.3540.1>@ejabberd_listener:accept:333 (#Port<0.123818>) Accepted connection 223.30.185.182:37374 -> *.*.*.*:5222
2016-12-20 12:35:18.763 [debug] <0.8492.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<?xml version='1.0'?><stream:stream  id='8' to='something.com' xmlns='jabber:client' version='1.0' xmlns:stream='http://etherx.jabber.org/streams'>">>
2016-12-20 12:35:18.763 [debug] <0.8493.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='11192005229436680642' from='something.com' version='1.0' xml:lang='en'>">>
2016-12-20 12:35:18.764 [debug] <0.8493.1>@ejabberd_c2s:send_text:1852 Send XML on stream = <<"<stream:features><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='Xe/lYmivnmPRh4GEsNf6U13V4G8='/><register xmlns='http://jabber.org/features/iq-register'/><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism><mechanism>DIGEST-MD5</mechanism><mechanism>X-OAUTH2</mechanism><mechanism>SCRAM-SHA-1</mechanism></mechanisms></stream:features>">>
2016-12-20 12:35:19.210 [debug] <0.8488.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<"<starttls xmlns=\"urn:ietf:params:xml:ns:xmpp-tls\"/>">>
2016-12-20 12:35:19.210 [debug] <0.8488.1>@shaper:update:120 State: {maxrate,500000000,0.0,1482217516980265}, Size=51
M=5.1e-5, I=2230.46
2016-12-20 12:35:19.211 [debug] <0.8488.1>@ejabberd_receiver:process_data:284 Received XML on stream = <<>>
2016-12-20 12:35:19.211 [debug] <0.8488.1>@shaper:update:120 State: {maxrate,500000000,11.43193760582948,1482217519210858}, Size=0
M=0.0, I=0.277
1

There are 1 answers

0
Alexey Dmitriev On

Here is an example of my tsung xml file which working well with starttls:

<?xml version="1.0"?>
<!DOCTYPE tsung SYSTEM "/home/ubuntu/tsung-1.7.0/tsung-1.0.dtd" []>
<tsung loglevel="warning" dumptraffic="false" version="1.0">

    <clients>
        <client host="localhost" use_controller_vm="false" cpu="8" maxusers="100000">
        </client>
    </clients>

    <servers>
        <server host="xmpp.example.com" port="5222" type="tcp"/>
    </servers>

    <load duration="30" unit="minute">
        <!--user session="jabber-login" start_time="2" unit="second"></user-->
        <!-- to make 24k online users -->
        <arrivalphase phase="1" duration="30" unit="minute">
          <users arrivalrate="20" unit="second"></users>
          <session_setup name="jabber-login" probability="100"/>
        </arrivalphase>
    </load>

    <options>
        <option type="ts_jabber" name="global_number" value="500"/>
        <option type="ts_jabber" name="userid_max" value="1000000"/>
        <option type="ts_jabber" name="domain" value="mylowdown.com"/>
        <option type="ts_jabber" name="username" value="tsung_"/>
        <option type="ts_jabber" name="passwd" value="tsung_pwd"/>
    </options>

    <sessions>
        <session probability="0" name="jabber-login" type="ts_jabber" bidi="true">

            <transaction name="connect">
                <request> <jabber type="connect" ack="local" /> </request>
                <thinktime value="5"></thinktime>
                <request> <jabber type="starttls" ack="bidi_ack" /> </request>
                <request> <jabber type="connect" ack="local" /> </request>
            </transaction>

            <thinktime value="5"></thinktime>

            <transaction name="authenticate">
                <request> <jabber type="auth_sasl" ack="local"/> </request>
                <request> <jabber type="connect" ack="local"/> </request>
                <request> <jabber type="auth_sasl_bind" ack="local"/> </request>
                <request> <jabber type="auth_sasl_session" ack="local"/> </request>
            </transaction>

            <transaction name="online">
                <request> <jabber type="presence:initial" ack="no_ack"/> </request>
            </transaction>

            <thinktime value="5"></thinktime>

            <for var="counter" from="1" to="21" incr="1">
                <transaction name="online_msg">
                    <request>
                        <jabber type="chat" ack="no_ack" size="40" stamped="true" destination="online"/>
                    </request>
                </transaction>

                <thinktime value="15"/>

                <transaction name="offline_msg">
                    <request>
                        <jabber type="chat" ack="no_ack" size="10" stamped="true" destination="offline"/>
                    </request>
                </transaction>
                <thinktime value="15"/>
            </for>

            <transaction name="close">
              <request> <jabber type="close" ack="local"> </jabber></request>
            </transaction>
        </session>
    </sessions>
</tsung>