Hi everyone,
I've tried to debug issues with "struct.error: unpack requires a string
argument of length 4" I experience on my machine
(http://code.google.com/p/spyderlib/issues/detail?id=113#c6). So I've
inserted a lot of debug statements all over bsdsocket.debug.diff - I don't
remember the exact reason why I chose to write debug info to file -
probably printing caused a deadlock.
Anyway, the corresponding diff for debugging bsdsocket is in attach, and
instead of solving my issue I've run into a bigger problem - with this diff
applied Spyder freezes after several seconds after editor becomes
operational. I suspect this happens when object inspector fires, but I am
not sure.
I've debugged deadlock using the method I've just described at
http://code.google.com/p/spyderlib/wiki/HowToDebugDeadlock and it seems
that the problem is that in bsdsocket.communicate() something fails to
respond to socket read, probably waiting for a lock.
I could dig further, but the thing that bugs me most is that even if it is
a race condition - it is 100% time repeatable with debug patch turned on,
and doesn't appear without it. I need some help from the experts in
threading to answer if a file I/O writes to the single debug log file from
multiple threads can be the reason for the proactive heisenbug deadlock?
--
anatoly t.
--
You received this message because you are subscribed to the Google Groups
"spyder" group.
To view this discussion on the web visit
https://groups.google.com/d/msg/spyderlib/-/bSvi9j6Q_2gJ.
To post to this group, send email to [email protected].
To unsubscribe from this group, send email to
[email protected].
For more options, visit this group at
http://groups.google.com/group/spyderlib?hl=en.
diff -r b922b235bf68 spyderlib/utils/bsdsocket.py
--- a/spyderlib/utils/bsdsocket.py Sat Mar 17 12:32:26 2012 +0300
+++ b/spyderlib/utils/bsdsocket.py Sat Mar 17 19:02:17 2012 +0300
@@ -15,17 +15,47 @@
import cPickle as pickle
import threading
+DEBUG = True
+#DEBUG = False
+
+if DEBUG:
+ logfile = open('bsdsocket_debug.log', 'w', 0)
+ logfile.write('---[debug log started]---\n')
+ logfile.write('R/W.SOCKET.COUNTER (LEN) <TYPE/PICKLED> DUMP\n')
+
+ def tohex(data):
+ import binascii
+ return binascii.hexlify(data)
+
+
+# [ ] todo - move it into a socket class
+write_counter = 0
+read_counter = 0
+
SZ = struct.calcsize("l")
def write_packet(sock, data, already_pickled=False):
"""Write *data* to socket *sock*"""
+ global write_counter
+ write_counter += 1
+ if DEBUG:
+ prefix = "W%02d.%02d" % (sock.fileno(), write_counter)
+ logfile.write("%s (%s) <%s/%s>" %
+ (prefix, len(data), type(data).__name__, already_pickled))
+ logfile.write(" %s\n" % (repr(data)))
if already_pickled:
sent_data = data
else:
sent_data = pickle.dumps(data, pickle.HIGHEST_PROTOCOL)
- sock.send(struct.pack("l", len(sent_data)) + sent_data)
+ packet = struct.pack("l", len(sent_data)) + sent_data
+ # [ ] check the number of bytes sent
+ sent = sock.send(packet)
+ if DEBUG:
+ # SOCKET/COUNTER (sent/len) hexdump
+ logfile.write("%s (%s/%s) %s\n" %
+ (prefix, sent, len(packet), tohex(packet)))
def read_packet(sock, timeout=None):
@@ -33,24 +63,41 @@
Read data from socket *sock*
Returns None if something went wrong
"""
+ global read_counter
+ read_counter += 1
+ if DEBUG:
+ prefix = "R%02d.%02d" % (sock.fileno(), read_counter)
+ logfile.write("%s " % (prefix))
sock.settimeout(timeout)
dlen, data = None, None
try:
datalen = sock.recv(SZ)
+ if DEBUG:
+ logfile.write("len(len):%s\n" % (len(datalen)))
dlen, = struct.unpack("l", datalen)
+ if DEBUG:
+ logfile.write("%s (%s) " % (prefix, dlen))
data = ''
while len(data) < dlen:
data += sock.recv(dlen)
+ if DEBUG:
+ logfile.write("%s\n" % (tohex(data)))
except socket.timeout:
raise
except socket.error:
+ if DEBUG:
+ logfile.write("%s ERROR: socket.error\n" % prefix)
data = None
finally:
sock.settimeout(None)
if data is not None:
try:
+ if DEBUG:
+ logfile.write("%s %s\n" % (prefix, repr(pickle.loads(data))))
return pickle.loads(data)
except (EOFError, pickle.UnpicklingError):
+ if DEBUG:
+ logfile.write("%s ERROR: unpickling\n" % prefix)
return
