Frequent connection close with 1006 going away error message

344 views
Skip to first unread message

Waseem Riaz

unread,
Apr 28, 2015, 10:29:33 AM4/28/15
to ws...@googlegroups.com
Hi,
I am using ws4py threaded-client to connect with border-connect server. an example of that is demonstrated here at https://borderconnect.com/borderconnect/api/index.htm.
The issue is whenever i connect to border-connect server the threaded-client automatically sends a closing request to border-connect right after a few seconds of opening connection.
What i want is threaded-client do not send any close requests as i am closing connection manually after a fixed amount of time.
many messages are missed because of this frequent disconnection.
Can any one suggest on how to stop that auto connection close call.

Any help is appreciated.

Below is the code that i have implemented for client side.

from ws4py.client.threadedclient import WebSocketClient
import json
import MySQLdb
import smtplib
import datetime
import time
import threading
import sys

class BorderConnectClient(WebSocketClient):

    db = ""
    dbcursor = ""
    
    dbhost = "********"
    dbuser = "*********"
    dbpass = "*************"
    dbname = "***********"
    
    connected = False

    start_time = datetime.datetime.now().strftime("%Y-%m-%d %I:%M:%S")
    max_time = datetime.datetime.now() + datetime.timedelta(hours = 5)

    def setup_database(self):

        # Open database connection
        db = MySQLdb.connect(self.dbhost, self.dbuser, self.dbpass, self.dbname )
        self.db = db

        # Prepare a cursor object using cursor() method
        cursor = db.cursor()
        self.dbcursor = cursor

        db.commit()

    # On connection open, send api keys
    def opened( self ):
        print "opened"
        self.send( '{ "apiKey": "************************" }' )
        print "Api key sent"

    def received_message(self, response):

        
        content = json.loads(response.data.decode( "utf-8" ))
        content['localTime'] = datetime.datetime.now().strftime("%Y-%m-%d %I:%M:%S")

        print content
        
        if content:
                
            # Save response in DB
            insert_sql = "INSERT INTO border_connect_manifest SET request_type = '1', json_string = '%s' " % MySQLdb.escape_string(json.dumps(content)) 
            self.dbcursor.execute(insert_sql)
            self.db.commit()

            # Just connected to borderConnect, Start Sending Requests
            if content['status'] == 'OK' and content['message'] == 'Connected':
                self.connected = True
                self.send_requests()

    def send_requests(self):

        print "Sending request called"
        
        if self.connected:

            cursor = self.dbcursor
            
            # update database with current time to check life of connection
            cursor.execute("UPDATE bc_cron_counter SET last_update = CURRENT_TIMESTAMP WHERE id = '1' ")
            self.db.commit()
            
            wait_seconds = 0

            # Get unprocessed requests to be sent
            cursor.execute("SELECT * FROM border_connect_manifest WHERE request_type = '0' AND processed = '0' LIMIT 50 ")

            # Converting all records to dict rows
            desc = cursor.description

            rows_dict = [

                dict(zip([col[0] for col in desc], row))

                for row in cursor.fetchall()

            ]

            # Send request to border connect and mark as processed
            for row in rows_dict:

                self.send(row['json_string'])
                cursor.execute("UPDATE border_connect_manifest SET processed = '1' WHERE id = '%s' " % row['id'])
                self.db.commit()

            # if total returned rows are less than 50 then delay next call for 1 minute
            if len(rows_dict) < 50 or not self.connected:
                print "wait 60 seconds"
                wait_seconds = 60
            
            # Close the connection if current time exceeds max time i.e 12 hours
            if datetime.datetime.now() >= self.max_time:
                self.close(reason='Max Time reached')
                self.connected = False

            else:
                time_interval = threading.Timer(wait_seconds, self.send_requests)
                time_interval.start()
            
    def closed(self, code, reason):
        self.connected = False

        close_time = datetime.datetime.now().strftime("%Y-%m-%d %I:%M:%S")
        close_data = json.dumps({'connection_closed': '%s' % close_time, 'reason': '%s' % reason})
        
        insert_sql = "INSERT INTO border_connect_manifest SET request_type = '1', json_string = '%s' " % MySQLdb.escape_string(close_data)
        self.dbcursor.execute(insert_sql)
        self.db.commit()
        
        print("Closed Down "+str(code)+" "+str(reason))
        self.db.close()

client = BorderConnectClient('wss://borderconnect.com/api/sockets/companyname')
print "Setup Database"
client.setup_database()

# Check for last request time
cursor = client.dbcursor
cursor.execute("SELECT last_update FROM bc_cron_counter WHERE id = '1' LIMIT 1 ")
row = cursor.fetchone()

# Check if last request was 3 minutes ago, Connection is closed. Start New Connection
if row[0] + datetime.timedelta(minutes=3) < datetime.datetime.now():
    print "Start Connection"
    client.connect()
    client.run_forever()

Sylvain Hellegouarch

unread,
Apr 28, 2015, 10:49:26 AM4/28/15
to ws...@googlegroups.com
Hi Waseem,

I'm curious as to why the connection would be closed automatically. Do you see a socket issue? Do you receive a close message from the server?

Thanks,

--
You received this message because you are subscribed to the Google Groups "ws4py" group.
To unsubscribe from this group and stop receiving emails from it, send an email to ws4py+un...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.



--

Waseem Riaz

unread,
Apr 28, 2015, 11:28:55 AM4/28/15
to ws...@googlegroups.com
Hi Sylvain Hellegouarch,
Thanks for replying.

Here are some records that are saved in db using that code. (More explanation at the end)

connected : 2015-04-28 03:25:02
Active Connections : 1
Closed : 2015-04-28 03:20:05
 
Reason : Going away
connected : 2015-04-27 03:20:01
Active Connections : 1
Closed : 2015-04-27 03:15:05
 
Reason : Going away
connected : 2015-04-27 03:15:01
Active Connections : 1
Closed : 2015-04-27 03:10:05
 
Reason : Going away
connected : 2015-04-26 03:10:02
Active Connections : 1
Closed : 2015-04-26 03:05:05
 
Reason : Going away
connected : 2015-04-26 03:05:01
Active Connections : 1
Closed : 2015-04-26 03:00:06
 
Reason : Going away
connected : 2015-04-25 03:00:02
Active Connections : 1
Closed : 2015-04-25 02:55:05
 
Reason : Going away
connected : 2015-04-25 02:55:01
Active Connections : 1
Closed : 2015-04-25 02:50:05
 
Reason : Going away
connected : 2015-04-24 02:50:01
Active Connections : 1
Closed : 2015-04-24 02:45:05
 
Reason : Going away
connected : 2015-04-24 02:45:01
Active Connections : 1
Closed : 2015-04-24 02:40:04
 
Reason : Going away
connected : 2015-04-23 02:40:01
Active Connections : 1
Closed : 2015-04-23 02:35:05
 
Reason : Going away
connected : 2015-04-23 02:35:01
Active Connections : 1
Closed : 2015-04-23 02:30:05
 
Reason : Going away
connected : 2015-04-22 02:30:01
Active Connections : 1
Closed : 2015-04-22 02:25:05
 
Reason : Going away
connected : 2015-04-22 02:25:01
Active Connections : 1
Closed : 2015-04-22 02:20:05
 
Reason : Going away
connected : 2015-04-21 02:20:01
Active Connections : 1
Closed : 2015-04-21 02:15:05
 
Reason : Going away
connected : 2015-04-21 02:15:01
Active Connections : 1
Closed : 2015-04-21 02:10:05
 
Reason : Going away
connected : 2015-04-20 02:10:01
Active Connections : 1
Closed : 2015-04-20 02:05:05
 
Reason : Going away
connected : 2015-04-20 02:05:01
Active Connections : 1
Closed : 2015-04-20 02:00:04
 
Reason : Going away
connected : 2015-04-19 02:00:01
Active Connections : 1
Closed : 2015-04-19 01:55:05
 
Reason : Going away
connected : 2015-04-19 01:55:01
Active Connections : 1
Closed : 2015-04-19 01:50:05
 
Reason : Going away
connected : 2015-04-18 01:50:01
Active Connections : 1
Closed : 2015-04-18 01:45:06
 
Reason : Going away
connected : 2015-04-18 01:45:01
Active Connections : 1
Closed : 2015-04-18 01:40:05
 
Reason : Going away
connected : 2015-04-17 01:40:01
Active Connections : 1
Closed : 2015-04-17 01:35:05
 
Reason : Going away
connected : 2015-04-17 01:35:02
Active Connections : 1
Closed : 2015-04-17 01:30:19
 
Reason : Going away
Receive Request
Processed: 1
---------------------
Array
(
   
[data] => ACI_RESPONSE
   
[dateTime] => 2015-04-02 13:45:31
   
[tripNumber] => 5452ACI30
   
[type] => ACCEPT
   
[sendRequest] => Array
       
(
           
[type] => ORIGINAL
           
[bundleTripAndShipments] => 1
           
[tripNumber] => 5452ACI30
       
)

   
[cbsaDateTime] => 2015-04-02 13:40:00
   
[localTime] => 2015-04-17 01:30:19
)

connected : 2015-04-17 01:30:02
Active Connections : 1
Closed : 2015-04-17 01:25:19
 
Reason : Going away
Receive Request
Processed: 1
---------------------
Array
(
   
[data] => ACI_RESPONSE
   
[dateTime] => 2015-04-02 13:45:31
   
[tripNumber] => 5452ACI27
   
[type] => ACCEPT
   
[sendRequest] => Array
       
(
           
[type] => ORIGINAL
           
[bundleTripAndShipments] => 1
           
[tripNumber] => 5452ACI27
       
)

   
[cbsaDateTime] => 2015-04-02 13:40:00
   
[localTime] => 2015-04-17 01:25:19
)

connected : 2015-04-17 01:25:02
Active Connections : 1
Closed : 2015-04-17 01:20:19
 
Reason : Going away
Receive Request
Processed: 1
---------------------
Array
(
   
[validationResponses] => Array
       
(
           
[0] => Array
               
(
                   
[code] => 418
                   
[description] => Duplicate Trip Number
                   
[reference] => Trip [WINXACE36]
               
)

           
[1] => Array
               
(
                   
[code] => 509
                   
[description] => Manifest Rejected
                   
[reference] => Trip [WINXACE36]
               
)

       
)

   
[processingResponse] => Array
       
(
           
[shipmentsRejected] => 1
           
[shipmentsAccepted] => 0
       
)

   
[dateTime] => 2015-04-02 13:26:04
   
[cbpDateTime] => 2015-04-02 13:25:45
   
[sendRequest] => Array
       
(
           
[tripNumber] => WINXACE36
           
[type] => COMPLETE_TRIP_AND_SHIPMENTS
       
)

   
[data] => ACE_RESPONSE
   
[localTime] => 2015-04-17 01:20:19
)

connected : 2015-04-17 01:20:02
Active Connections : 1
Closed : 2015-04-17 01:15:19
 
Reason : Going away
Receive Request
Processed: 1
---------------------
Array
(
   
[validationResponses] => Array
       
(
           
[0] => Array
               
(
                   
[code] => 418
                   
[description] => Duplicate Trip Number
                   
[reference] => Trip [WINXACE31]
               
)

           
[1] => Array
               
(
                   
[code] => 509
                   
[description] => Manifest Rejected
                   
[reference] => Trip [WINXACE31]
               
)

       
)

   
[processingResponse] => Array
       
(
           
[shipmentsRejected] => 1
           
[shipmentsAccepted] => 0
       
)

   
[dateTime] => 2015-04-02 13:26:04
   
[cbpDateTime] => 2015-04-02 13:25:45
   
[sendRequest] => Array
       
(
           
[tripNumber] => WINXACE31
           
[type] => COMPLETE_TRIP_AND_SHIPMENTS
       
)

   
[data] => ACE_RESPONSE
   
[localTime] => 2015-04-17 01:15:19
)

connected : 2015-04-17 01:15:02
Active Connections : 1
Closed : 2015-04-17 01:10:19
 
Reason : Going away
Receive Request
Processed: 1
---------------------
Array
(
   
[processingResponse] => Array
       
(
           
[shipmentsRejected] => 0
           
[shipmentsAccepted] => 1
       
)

   
[dateTime] => 2015-04-02 13:30:03
   
[cbpDateTime] => 2015-04-02 13:29:37
   
[sendRequest] => Array
       
(
           
[tripNumber] => WINXACE30
           
[type] => COMPLETE_TRIP_AND_SHIPMENTS
       
)

   
[data] => ACE_RESPONSE
   
[localTime] => 2015-04-17 01:10:19
)

connected : 2015-04-17 01:10:01
Active Connections : 1
Closed : 2015-04-17 01:05:05
 
Reason : Going away
connected : 2015-04-16 01:05:01
Active Connections : 1
Closed : 2015-04-16 12:59:18
 
Reason : Max Time reached
connected : 2015-04-16 12:57:18
Active Connections : 1
Closed : 2015-04-16 12:53:19
 
Reason : Max Time reached
connected : 2015-04-16 12:51:19
Active Connections : 1


Now if you see here starting from end the first close response Max Time Reached, this message appears when i manually close the connection.
but right after a few seconds Going away close connection is received in closed method. this one is the problem.
This message is received right after few seconds no matter i receive a message or not as you can see received messages started with "
Receive Request"
"Receive Request" are the responses that are received from border-connect and missed many times because of frequent connection close.

We also contacted border-connect support for this issue, they reviewed our code and marked it as Ok. but still we have this issue. so now i am here to get some suggestions on how to improve it. so i can receive all responses.

Sylvain Hellegouarch

unread,
Apr 28, 2015, 2:40:46 PM4/28/15
to ws...@googlegroups.com
Mmmh, I cannot clearly say why it automatically terminates:

* Could you run a tcpdump to see the exchange with the server? Maybe, the server does send something odd?
* You shouldn't use a timer thread in send_requests, you probably want something like:

def send_requests(...):

     while self.connected:

          ...
          else:
              time.sleep(wait_seconds)





--
You received this message because you are subscribed to the Google Groups "ws4py" group.
To unsubscribe from this group and stop receiving emails from it, send an email to ws4py+un...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Waseem Riaz

unread,
Apr 29, 2015, 8:33:37 AM4/29/15
to ws...@googlegroups.com
The reason i am using timer is that if i use sleep function then whole script hangs for some time and so i miss even more messages. 
can you please tell me where to do tcpdump ? 

Waseem Riaz

unread,
Apr 30, 2015, 11:00:47 AM4/30/15
to ws...@googlegroups.com
Is there a way i can stop that close call to server on receiving nothing ?
I just want every response to be passed to received_message(). no matter it contains some thing or not.
please tell me if i can do that. one way i thought of is to comment that particular line of code which send 1006 going away request in ws4py/websocket.py
I am still unable to resolve missing messages issue.
Reply all
Reply to author
Forward
0 new messages