testpickle.log

[1] 27203
PY2 ___ 15:06:15  27203     INFO : serving on localhost:11166
PY2 ___ 15:06:17  27203    DEBUG : Client connected
___ PY3 15:06:17  27224    DEBUG : Writing 'b'gAJjZGF0ZXRpbWUKZGF0ZXRpbWUKcQBjX2NvZGVjcwplbmNvZGUKcQFYDAAAAAfDngcRDwYRBQrCkHECWAYAAABsYXRpbjFxA4ZxBFJxBYVxBlJxBy4=''
PY2 ___ 15:06:17  27203    DEBUG : Raw query 'gAJjZGF0ZXRpbWUKZGF0ZXRpbWUKcQBjX2NvZGVjcwplbmNvZGUKcQFYDAAAAAfDngcRDwYRBQrCkHECWAYAAABsYXRpbjFxA4ZxBFJxBYVxBlJxBy4=
'
---------------- PickleTools ---------------
    0: \x80 PROTO      2
    2: c    GLOBAL     'datetime datetime'
   21: q    BINPUT     0
   23: c    GLOBAL     '_codecs encode'
   39: q    BINPUT     1
   41: X    BINUNICODE u'\x07\xde\x07\x11\x0f\x06\x11\x05\n\x90'
   58: q    BINPUT     2
   60: X    BINUNICODE u'latin1'
   71: q    BINPUT     3
   73: \x86 TUPLE2
   74: q    BINPUT     4
   76: R    REDUCE
   77: q    BINPUT     5
   79: \x85 TUPLE1
   80: q    BINPUT     6
   82: R    REDUCE
   83: q    BINPUT     7
   85: .    STOP
highest protocol among opcodes = 2
-------------- End PickleTools -------------
PY2 ___ 15:06:17  27203    DEBUG : Processing '2014-07-17 15:06:17.330384'
PY2 ___ 15:06:17  27203    DEBUG : Encoding reply: (datetime.datetime(2014, 7, 17, 15, 6, 17, 330384), [], None)
PY2 ___ 15:06:17  27203    DEBUG : Pickled: '\x80\x02cdatetime\ndatetime\nq\x00U\n\x07\xde\x07\x11\x0f\x06\x11\x05\n\x90q\x01\x85q\x02Rq\x03]q\x04N\x87q\x05.'
PY2 ___ 15:06:17  27203    DEBUG : Raw reply: 'gAJjZ'...'HcQUu'
___ PY3 15:06:17  27224    DEBUG : Received Raw: ...b'cQUu\n' -> Pickled: b'\x80\x02cdatetime\ndatetime\nq\x00U\n\x07\xde\x07\x11\x0f\x06\x11\x05\n\x90q\x01\x85q\x02Rq\x03]q\x04N\x87q\x05.'
---------------- PickleTools ---------------
    0: \\x80 PROTO      2
    2: c    GLOBAL     'datetime datetime'
   21: q    BINPUT     0
   23: U    SHORT_BINSTRING '\\x07\xc3\x9e\\x07\\x11\\x0f\\x06\\x11\\x05\
\\x90'
   35: q    BINPUT     1
   37: \\x85 TUPLE1
   38: q    BINPUT     2
   40: R    REDUCE
   41: q    BINPUT     3
   43: ]    EMPTY_LIST
   44: q    BINPUT     4
   46: N    NONE
   47: \\x87 TUPLE3
   48: q    BINPUT     5
   50: .    STOP
highest protocol among opcodes = 2
-------------- End PickleTools -------------
(<class 'TypeError'>, TypeError('an integer is required (got type str)',), <traceback object at 0x7f42454bf708>)
<class 'datetime.datetime'>  
---------- Stacktrace with locals ---------- 
UnicodeEncodeError :  'ascii' codec can't encode character '\xde' in position 6: ordinal not in range(128)
  File "/remote/users/eoubrayrie/ato/otoi/debug/testpickle.py", line 164, in test
    (search, msgs, exc) = pickle._loads(standard_b64decode(source), fix_imports=True, encoding='latin1')#, encoding='utf-8')
        {'pickled': b'\x80\x02cdatetime\ndatetime\nq\x00U\n\x07\xde\x07\x11\x0f\x06\x11\x05\n\x90q\x01\x85q\x02Rq\x03]q\x04N\x87q\x05.',
         'raws': b'gAJjZGF0ZXRpbWUKZGF0ZXRpbWUKcQBjX2NvZGVjcwplbmNvZGUKcQFYDAAAAAfDngcRDwYRBQrCkHECWAYAAABsYXRpbjFxA4ZxBFJxBYVxBlJxBy4=',
         'search': datetime.datetime(2014, 7, 17, 15, 6, 17, 330384),
         'self': <__main__.TestPickle object at 0x7f4245cd1ba8>,
         'source': b'gAJjZGF0ZXRpbWUKZGF0ZXRpbWUKcQBVCgfeBxEPBhEFCpBxAYVxAlJxA11xBE6HcQUu\n'}
  File "/data2/eoubrayrie/soft/python3/lib/python3.4/pickle.py", line 1552, in _loads
    encoding=encoding, errors=errors).load()
        {'encoding': 'latin1',
         'errors': 'strict',
         'file': <_io.BytesIO object at 0x7f42454cf0a8>,
         'fix_imports': True,
         's': b'\x80\x02cdatetime\ndatetime\nq\x00U\n\x07\xde\x07\x11\x0f\x06\x11\x05\n\x90q\x01\x85q\x02Rq\x03]q\x04N\x87q\x05.'}
  File "/data2/eoubrayrie/soft/python3/lib/python3.4/pickle.py", line 1036, in load
    dispatch[key[0]](self)
        {'dispatch': {40: <function _Unpickler.load_mark at 0x7f4246199a60>,
                      41: <function _Unpickler.load_empty_tuple at 0x7f4246198510>,
                      46: <function _Unpickler.load_stop at 0x7f4246199ae8>,
                      48: <function _Unpickler.load_pop at 0x7f42461991e0>,
                      49: <function _Unpickler.load_pop_mark at 0x7f4246199268>,
                      50: <function _Unpickler.load_dup at 0x7f42461992f0>,
                      66: <function _Unpickler.load_binbytes at 0x7f42461980d0>,
                      67: <function _Unpickler.load_short_binbytes at 0x7f4246198378>,
                      70: <function _Unpickler.load_float at 0x7f4246197d90>,
                      71: <function _Unpickler.load_binfloat at 0x7f4246197e18>,
                      73: <function _Unpickler.load_int at 0x7f42461979d8>,
                      74: <function _Unpickler.load_binint at 0x7f4246197a60>,
                      75: <function _Unpickler.load_binint1 at 0x7f4246197ae8>,
                      76: <function _Unpickler.load_long at 0x7f42
  File "/data2/eoubrayrie/soft/python3/lib/python3.4/pickle.py", line 1385, in load_reduce
    print(func, args)
        {'args': ('\\x07\xc3\x9e\\x07\\x11\\x0f\\x06\\x11\\x05\
\\x90',), 'func': <class 'datetime.datetime'>, 'self': <pickle._Unpickler object at 0x7f42454c6b70>, 'stack': [<class 'datetime.datetime'>]}
 ------------- End of stacktrace ------------ 
PY2 ___ 15:06:17  27203     INFO : Exiting at user command
[1]  + 27203 done       python2 ~/ato/otoi/debug/testpickle.py

testpickle.py

# -*- coding: utf-8 -*-

"""
Launch with:
python2 testpickle.py & ; sleep 2 ; python3 testpickle.py ; kill -s SIGINT $!
"""

from __future__ import division
from __future__ import print_function
from __future__ import absolute_import
from __future__ import unicode_literals

try:
    import socketserver  #PY3
    PY3 = True
except ImportError:
    # noinspection PyUnresolvedReferences
    import SocketServer as socketserver  # PY2
    PY3 = False

import sys
import socket
import pprint
import logging
import traceback
import pickle
import pickletools
from datetime import datetime
from base64 import standard_b64decode, standard_b64encode

prefix = '___ PY3' if PY3 else 'PY2 ___'
logformat = prefix + ' %(asctime)s %(process)6s %(levelname)8s : %(message)s'
dateformat = '%H:%M:%S'
logging.basicConfig(level=logging.DEBUG, format=logformat, datefmt=dateformat)
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

HOST = 'localhost'
PORT = 11166


############## Server Code #############

class SocketReceiver(socketserver.BaseRequestHandler):

    def handle(self):
        # noinspection PyBroadException
        try:
            self._handle()
        except:
            logger.warning('Uncaught server error, a request has been dropped -- deep locals:', exc_info=1)

    def _handle(self):
        # noinspection PyBroadException
        logger.debug("Client connected")
        reader = self.request.makefile('rb')
        writer = self.request.makefile('wb')
        qraw = reader.readline()  # was read()
        logger.debug("Raw query '%s'", qraw)
        pickled = standard_b64decode(qraw)
        pickle_debug(pickled)
        search = pickle.loads(pickled)
        logger.debug("Processing '%s'", search)

        reply = (search, [], None)

        logger.debug("Encoding reply: %s", reply)
        logger.debug("Pickled: %s", repr(pickle.dumps(reply, protocol=2)))
        rraw = standard_b64encode(pickle.dumps(reply, protocol=2))
        logger.debug("Raw reply: %s...%s", repr(rraw[:5]), repr(rraw[-5:]))
        writer.write(rraw)
        writer.write(b'\n')
        writer.flush()

def create_server():
    server = socketserver.TCPServer((HOST, PORT), SocketReceiver)
    logger.info("serving on %s:%d", HOST, PORT)
    try:
        server.serve_forever()
    except KeyboardInterrupt:
        server.shutdown()
        server.server_close()
        logger.info('Exiting at user command')


############## Client Code #############

COLOR = '\x1b[35m'
RESET = '\x1b[0m'


def safebytes(b):
    """ :type b: bytes """
    return repr(b)[2:-1].replace('\\t', '\t').replace('\\n', '\n')


def safestr(s):
    """ :type s: str """
    # noinspection PyTypeChecker
    return safebytes(s.encode('utf-8'))


def safeprint(*args, **kwargs):
    end = kwargs.get('end', '\n')
    kwargs['end'] = kwargs.get('sep', '')
    for a in args:
        try:
            print(a, **kwargs)
        except UnicodeEncodeError:
            if type(a) != bytes:
                a = str(a).encode('utf-8')
            print(safebytes(a), **kwargs)
    print(end, end='')
        

def stacktraceWithLocals(typ, value, frame):
    print(COLOR, '\n---------- Stacktrace with locals ----------', RESET)
    formattedTb = traceback.format_tb(frame)
    # frame = frame.tb_next
    print(typ.__name__, ': ', value)
    while frame:
        formattedFrame = formattedTb.pop(0)
        loc = pprint.pformat(frame.tb_frame.f_locals, width=200).replace('\n', '\n\t')[0:1000]
        safeprint(COLOR, formattedFrame, RESET, '\t', loc)
        frame = frame.tb_next
    print(COLOR, '------------- End of stacktrace ------------', RESET)


def pickle_debug(pickled):
    sys.stdout.flush()
    print('---------------- PickleTools ---------------')
    if PY3:
        import io
        out = io.StringIO()
        pickletools.dis(pickled, out=out)
        print(safestr(out.getvalue()), end='')
    else:
        pickletools.dis(pickled)
    print('-------------- End PickleTools -------------')
    sys.stdout.flush()


class TestPickle:
    def __init__(self):
        self.sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
        self.sock.connect((HOST, PORT))
        self.writer = self.sock.makefile('wb')
        self.reader = self.sock.makefile('rb')
        
    def test(self):
        search = datetime.now()
        raws = standard_b64encode(pickle.dumps(search, protocol=2))
        logger.debug("Writing '%s'", raws)
        self.writer.write(raws)
        self.writer.write(b'\n')
        self.writer.flush()
        
        source = self.reader.readline()
        pickled = standard_b64decode(source)
        logger.debug("Received Raw: ...%s -> Pickled: %s", source[-5:], repr(pickled))
        pickle_debug(pickled)
        # noinspection PyBroadException
        try:
            (search, msgs, exc) = pickle._loads(pickled, fix_imports=True, encoding='latin1')#, encoding='utf-8')
            logger.debug("Received %s %s %s", search, msgs, exc)
        except:
            stacktraceWithLocals(*sys.exc_info())


############## main Code #############

if __name__ == '__main__':
    if PY3:
        TestPickle().test()
    else:
        create_server()