Invalid packets on long running queries

Bug #329397 reported by Geert JM Vanderkelen
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MySQL Connector/Python
Fix Released
Critical
Geert JM Vanderkelen
Nominated for Trunk by Rhett Trappman
Ubuntu
Invalid
Undecided
Unassigned

Bug Description

Doing in I_S: SELECT * FROM TABLES a, TABLES b gives 'sometimes' an invalid packet length.

Header says length is 433, but buffer is 279 long

b1 01 00 dc fb 12 69 6e 66 6f 72 6d 61 74 69 6f 6e 5f 73 63 68 65 6d 61 05 56 49
45 57 53 0b 53 59 53 54 45 4d 20 56 49 45 57 06 4d 79 49 53 41 4d 02 31 30 07 44
79 6e 61 6d 69 63 fb 01 30 01 30 0f 32 38 31 34 37 34 39 37 36 37 31 30 36 35 35
04 31 30 32 34 01 30 fb 13 32 30 30 39 2d 30 32 2d 31 34 20 30 39 3a 35 34 3a 33
32 13 32 30 30 39 2d 30 32 2d 31 34 20 30 39 3a 35 34 3a 33 32 fb 0f 75 74 66 38
5f 67 65 6e 65 72 61 6c 5f 63 69 fb 0d 6d 61 78 5f 72 6f 77 73 3d 36 39 33 32 00
fb 12 69 6e 66 6f 72 6d 61 74 69 6f 6e 5f 73 63 68 65 6d 61 0a 43 4f 4c 4c 41 54
49 4f 4e 53 0b 53 59 53 54 45 4d 20 56 49 45 57 06 4d 45 4d 4f 52 59 02 31 30 05
46 69 78 65 64 fb 03 34 32 33 01 30 08 31 36 37 33 37 32 36 34 01 30 01 30 fb fb
fb fb 0f 75 74 66 38 5f 67 65 6e 65 72 61 6c 5f 63 69 fb 0e 6d 61 78 5f 72 6f 77
73 3d 33 39 36 36 32 00 fb 12 69 6e 66

Only seen on OpenSolaris for now. Worked fine on Mac OS.

(BTW, queries was just to make a test case..)

Tags: protocol

Related branches

Changed in myconnpy:
assignee: nobody → geertjmvdk
importance: Undecided → Critical
status: New → Confirmed
Revision history for this message
analogue (analogue-yahoo) wrote :

I think I'm running into this quite alot on on Linux (Ubuntu 9.04). Very hard to reproduce and non-deterministic in nature. Always results in 'Invalid Packet' on the RowDataPacket. Would a stack trace help or do you have enough information at this point to address the defect? My particular queries don't seem to be long running though they seem to occur more from my laptop connected via wifi than a desktop connected over gigabit ethernet so latency may have something to do with it. Any known workarounds?

Revision history for this message
Geert JM Vanderkelen (geertjmvdk) wrote :

Thanks for confirming you're getting it as well!

No workarounds, but I'll put this as a priority once I got other stuff pushed.

Revision history for this message
analogue (analogue-yahoo) wrote :

I have a workaround for this. Turns out is is more of the "i'm gettting less bytes than I requested from the socket connection".

from connection.py, the stock header= and buffer= have been commented out and replaced to use self.recv_all(). Try both scenarios and uncomment the "print" stmt and you will see the difference. To trigger the bug, just make sure your query returns alot of data.

    def recv(self):
        """
        Receive packets using the socket from the server.
        """
        try:
            #header = self.sock.recv(4, self.socket_flags)
            header = self.recv_all(self.sock, 4)
            (pktsize, pktnr) = self.protocol.handle_header(header)
            #buf = header + self.sock.recv(pktsize, self.socket_flags)
            buf = header + self.recv_all(self.sock, pktsize)
            #print('buflen=%d pktsize=%d pktnr=%d sum=%d' % (len(buf), pktsize, pktnr, pktsize + 4))
            self.protocol.is_error(buf)
        except socket.timeout, errmsg:
            raise InterfaceError('Timed out reading from socket.')

        return (buf, pktsize, pktnr)

    def recv_all(self, socket, bytes):
        """Receive an exact number of bytes.

        Regular Socket.recv() may return less than the requested number of bytes,
        dependning on what's in the OS buffer. MSG_WAITALL is not available
        on all platforms, but this should work everywhere. This will return
        less than the requested amount if the remote end closes.

        This isn't optimized and is intended mostly for use in testing.
        """
        b = ''
        while len(b) < bytes:
            left = bytes - len(b)
            try:
                new = socket.recv(left)
            except Exception, e:
                print('left bytes = %d out of %d' % (left, bytes))
                raise e
            if new == '':
                break # eof
            b += new
        return b

Revision history for this message
Geert JM Vanderkelen (geertjmvdk) wrote :

Before changing things, I would like to build a good test case for this bug.
I'm trying to make the result set big, but I'm failing to reproduce this on Linux (with latest pull).

For example, doing this:
  cursor.execute("SELECT REPEAT('0123456789abcdef',65536)")

Or getting all data from a table having:
  Avg_row_length: 202
    Data_length: 107916792

It would be good for the unittesting as well.

Revision history for this message
Gerry C. (ubuntunerd-nospammail) wrote :

Workaround created by bug reporter. No official patch released.

Changed in myconnpy:
status: Confirmed → In Progress
Revision history for this message
Geert JM Vanderkelen (geertjmvdk) wrote :

Gerry, you have a test case for this?

Revision history for this message
C de-Avillez (hggdh2) wrote :

Corrected upstream task back to confirmed; set Ubuntu task to Invalid. <sigh/>. Just spam from the commenter.

Changed in ubuntu:
status: New → Invalid
Changed in myconnpy:
status: In Progress → Confirmed
Revision history for this message
Geert JM Vanderkelen (geertjmvdk) wrote :

Attached is a patch which hopefully fixes #329397. Please try it out and see if it works.
I will commit/push this code soon but wanted to see some comments first.

What I did was refactoring the MySQLBaseConnection.recv() method:
* Keeps reading in chunks from socket until needed, get rid of MSG_WAITALL
* Consecutive packets are kept in a deque. If there is something in the deque, recv() will first use that data.

Overall, I think this is also faster.

Revision history for this message
Geert JM Vanderkelen (geertjmvdk) wrote :

I believe the patch for recv() is good, and it's the same idea as analogue's.
I'm pushing it. :)

Changed in myconnpy:
status: Confirmed → In Progress
Changed in myconnpy:
status: In Progress → Fix Committed
Changed in myconnpy:
milestone: none → 0.1.4
Changed in myconnpy:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.