Python 3.10.0a7 test_history:test_timestamp_type fails

[frenzymadness]

We are trying to test IPython with the latest Python 3.10.0a7 on Fedora and one test fails. I'm trying to debug it but I'm not able to reproduce it yet.

The original traceback is:

ERROR: IPython.core.tests.test_history.test_timestamp_type
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/lib/python3.10/site-packages/nose/case.py", line 197, in runTest
    self.test(*self.arg)
  File "/builddir/build/BUILDROOT/ipython-7.22.0-1.fc35.x86_64/usr/lib/python3.10/site-packages/IPython/core/tests/test_history.py", line 173, in test_timestamp_type
    info = ip.history_manager.get_session_info()
  File "/builddir/build/BUILDROOT/ipython-7.22.0-1.fc35.x86_64/usr/lib/python3.10/site-packages/IPython/core/history.py", line 631, in get_session_info
    return super(HistoryManager, self).get_session_info(session=session)
  File "<decorator-gen-10>", line 2, in get_session_info
  File "/builddir/build/BUILDROOT/ipython-7.22.0-1.fc35.x86_64/usr/lib/python3.10/site-packages/IPython/core/history.py", line 58, in needs_sqlite
    return f(self, *a, **kw)
  File "<decorator-gen-9>", line 2, in get_session_info
  File "/builddir/build/BUILDROOT/ipython-7.22.0-1.fc35.x86_64/usr/lib/python3.10/site-packages/IPython/core/history.py", line 87, in catch_corrupt_db
    return f(self, *a, **kw)
  File "/builddir/build/BUILDROOT/ipython-7.22.0-1.fc35.x86_64/usr/lib/python3.10/site-packages/IPython/core/history.py", line 331, in get_session_info
    return self.db.execute(query, (session,)).fetchone()
  File "/usr/lib64/python3.10/sqlite3/dbapi2.py", line 67, in convert_timestamp
    datepart, timepart = val.split(b" ")
ValueError: not enough values to unpack (expected 2, got 1)

If I pause the test and try to investigate the database, everything looks fine (lsof shows me where the file is):

# sqlite3 /tmp/tmpne7l2pz2test_hist.sqlite
SQLite version 3.35.4 2021-04-02 15:20:15
Enter ".help" for usage hints.
sqlite> .dump
PRAGMA foreign_keys=OFF;
BEGIN TRANSACTION;
CREATE TABLE sessions (session integer
                        primary key autoincrement, start timestamp,
                        end timestamp, num_cmds integer, remark text);
INSERT INTO sessions VALUES(1,'2021-04-13 09:44:58.903345',NULL,NULL,'');
CREATE TABLE history
                (session integer, line integer, source text, source_raw text,
                PRIMARY KEY (session, line));
INSERT INTO history VALUES(1,1,'a = 10','a = 10');
INSERT INTO history VALUES(1,2,'a += 1','a += 1');
INSERT INTO history VALUES(1,3,'get_ipython().run_line_magic(''rerun'', '''')','%rerun');
CREATE TABLE output_history
                        (session integer, line integer, output text,
                        PRIMARY KEY (session, line));
DELETE FROM sqlite_sequence;
INSERT INTO sqlite_sequence VALUES('sessions',1);
COMMIT;
sqlite>

I've tried to create the same table in the new database and open it directly in Python, and everything works:

# sqlite3 test.sqlite
SQLite version 3.35.4 2021-04-02 15:20:15
Enter ".help" for usage hints.
sqlite> CREATE TABLE sessions (session integer
                        primary key autoincrement, start timestamp,
                        end timestamp, num_cmds integer, remark text);
INSERT INTO sessions VALUES(1,'2021-04-13 09:44:58.903345',NULL,NULL,'');
sqlite> 
sqlite> select * from sessions;
1|2021-04-13 09:44:58.903345|||

[root@2e2bddad445a /]# python3
Python 3.10.0a7 (default, Apr  6 2021, 00:00:00) [GCC 11.0.1 20210405 (Red Hat 11.0.1-0)] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import sqlite3
>>> conn = sqlite3.connect('test.sqlite')
>>> c = conn.cursor()
>>> c.execute("SELECT * from sessions where session == 1").fetchone()
(1, '2021-04-13 09:44:58.903345', None, None, '')

convert_timestamp converter in dbapi2 is there untouched for many years. I've also tried to reproduce the issue with an older sqlite and everything behaves the same.

[frenzymadness]

Ok, now I know how to reproduce the issue in pure Python - the converters from dbapi2 have to be enabled manually:

# python3
Python 3.10.0a7 (default, Apr  6 2021, 00:00:00) [GCC 11.0.1 20210405 (Red Hat 11.0.1-0)] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import sqlite3
>>> conn = sqlite3.connect('test.sqlite', detect_types=sqlite3.PARSE_DECLTYPES)
>>> c = conn.cursor()
>>> c.execute("SELECT * from sessions where session == 1").fetchone()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/lib64/python3.10/sqlite3/dbapi2.py", line 67, in convert_timestamp
    datepart, timepart = val.split(b" ")
ValueError: not enough values to unpack (expected 2, got 1)

The question still is what is the pure return value from sqlite which the converter tries to parse.

[frenzymadness]

The answer is: the value converter gets to parse the timestamp is an empty bytestring:

# ipython
Python 3.10.0a7 (default, Apr  6 2021, 00:00:00) [GCC 11.0.1 20210405 (Red Hat 11.0.1-0)]
Type 'copyright', 'credits' or 'license' for more information
IPython 7.22.0 -- An enhanced Interactive Python. Type '?' for help.

In [1]: %pdb on                                                                               
Automatic pdb calling has been turned ON

In [2]: import sqlite3                                                                        

In [3]: conn = sqlite3.connect('test.sqlite', detect_types=sqlite3.PARSE_DECLTYPES)           

In [4]: c = conn.cursor()                                                                     

In [5]: c.execute("SELECT * from sessions where session == 1").fetchone()                     
---------------------------------------------------------------------------
ValueError                                Traceback (most recent call last)
<ipython-input-5-c234e57285e4> in <module>
----> 1 c.execute("SELECT * from sessions where session == 1").fetchone()

/usr/lib64/python3.10/sqlite3/dbapi2.py in convert_timestamp(val)
     65 
     66     def convert_timestamp(val):
---> 67         datepart, timepart = val.split(b" ")
     68         year, month, day = map(int, datepart.split(b"-"))
     69         timepart_full = timepart.split(b".")

ValueError: not enough values to unpack (expected 2, got 1)
> /usr/lib64/python3.10/sqlite3/dbapi2.py(67)convert_timestamp()
     65 
     66     def convert_timestamp(val):
---> 67         datepart, timepart = val.split(b" ")
     68         year, month, day = map(int, datepart.split(b"-"))
     69         timepart_full = timepart.split(b".")

ipdb> val                                                                                     
b''

[frenzymadness]

I think this is an error in Python so I'm gonna report it.

[frenzymadness]

Bug report: https://bugs.python.org/issue43831

In the end, it turned out that the problem is in the end column and not in the start column. Python tries to parse the empty column and fails on the first operation.

[MrMino]

Note to self: the original BPO issue is in stage: patch review.

[MrMino]

@frenzymadness looks like the BPO ticket is fixed. Could you please confirm?

[willingc]

@MrMino @frenzymadness The PR has been merged. Please let us know if you still see the error on the latest branch of CPython.

[frenzymadness]

I've tried to run the tests but the pytest is not compatible with the latest Python :( pytest-dev/pytest#8539

[frenzymadness]

pytest is fixed now so with pytest from its master branch:

python -m pytest venv/lib/python3.10/site-packages/IPython/core/tests/test_history.py
==================================== test session starts =====================================
platform linux -- Python 3.10.0a7+, pytest-6.3.0.dev367+gaf31c60db, py-1.10.0, pluggy-0.13.1
rootdir: /home/lbalhar/Software/cpython
collected 7 items                                                                            

venv/lib/python3.10/site-packages/IPython/core/tests/test_history.py .s.....           [100%]

====================================== warnings summary ======================================
venv/lib/python3.10/site-packages/nose/importer.py:12
  /home/lbalhar/Software/cpython/venv/lib/python3.10/site-packages/nose/importer.py:12: DeprecationWarning: the imp module is deprecated in favour of importlib and slated for removal in Python 3.12; see the module's documentation for alternative uses
    from imp import find_module, load_module, acquire_lock, release_lock

-- Docs: https://docs.pytest.org/en/stable/warnings.html
========================== 6 passed, 1 skipped, 1 warning in 0.04s ===========================

This issue can be closed, thank you!

[MrMino]

Thanks @frenzymadness !