<story><title>Bug #915: Please help</title><url>https://nedbatchelder.com/blog/202001/bug_915_please_help.html</url></story><parent_chain></parent_chain><comment><author>nneonneo</author><text>This doesn&amp;#x27;t quite get all the way there, but the failure is being caused by the closure of a _io.FileIO due to GC, which happens to have the same fd as the sqlite database. The closure happens in the middle of a SQLite operation, which causes a subsequent flock() call to fail.&lt;p&gt;strace log from the failure:&lt;p&gt;&lt;pre&gt;&lt;code&gt;    open(&amp;quot;&amp;#x2F;home&amp;#x2F;travis&amp;#x2F;apprise-api&amp;#x2F;.coverage&amp;quot;, O_RDWR|O_CREAT|O_CLOEXEC, 0644) = 31
    fstat(31, {st_mode=S_IFREG|0644, st_size=192512, ...}) = 0
    fstat(31, {st_mode=S_IFREG|0644, st_size=192512, ...}) = 0
    lseek(31, 0, SEEK_SET)                  = 0
    read(31, &amp;quot;SQLite format 3\0\4\0\1\1\0@  \0\0\0\n\0\0\0\274&amp;quot;..., 100) = 100
    write(3, &amp;quot;00001299 0001 6169 execute(&amp;#x27;prag&amp;quot;..., 54) = 54
    write(3, &amp;quot;Executing &amp;#x27;pragma journal_mode=o&amp;quot;..., 36) = 36
    write(3, &amp;quot;self: &amp;lt;SqliteDb @0x7fa0feef9fd0 &amp;quot;..., 86) = 86
    fcntl(31, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
    fcntl(31, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
    fcntl(31, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
    fstat(31, {st_mode=S_IFREG|0644, st_size=192512, ...}) = 0
    fstat(31, {st_mode=S_IFREG|0644, st_size=192512, ...}) = 0
    lseek(31, 0, SEEK_SET)                  = 0
    read(31, &amp;quot;SQLite format 3\0\4\0\1\1\0@  \0\0\0\n\0\0\0\274&amp;quot;..., 1024) = 1024
    lseek(31, 8192, SEEK_SET)               = 8192
    read(31, &amp;quot;\r\3-\0\4\0\316\0\3^\1X\0035\0\316\0\245\0v\0v\0\0\0\0\0\0\0\0\0\0&amp;quot;..., 1024) = 1024
    lseek(31, 9216, SEEK_SET)               = 9216
    read(31, &amp;quot;\r\0\0\0\4\0\370\0\0\370\3d\0035\1!\0\277\0\277\2\36\0\0\0\0\0\0\0\0\0\0&amp;quot;..., 1024) = 1024
    lseek(31, 14336, SEEK_SET)              = 14336
    read(31, &amp;quot;\r\0\0\0\4\0\320\0\3\315\1\313\1\244\0\320\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0&amp;quot;..., 1024) = 1024
    fcntl(31, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
    write(3, &amp;quot;00001299 0001 6169 execute retur&amp;quot;..., 76) = 76
    write(3, &amp;quot;00001299 0001 6170 execute(&amp;#x27;prag&amp;quot;..., 53) = 53
    write(3, &amp;quot;Executing &amp;#x27;pragma synchronous=of&amp;quot;..., 35) = 35
    lseek(31, 0, SEEK_CUR)                  = 15360
    close(31)                               = 0
    write(3, &amp;quot;self: &amp;lt;SqliteDb @0x7fa0feef9fd0 &amp;quot;..., 86) = 86
    write(3, &amp;quot;00001299 0001 6170 execute retur&amp;quot;..., 76) = 76
    write(3, &amp;quot;00001299 0001 6168 _connect retu&amp;quot;..., 40) = 40
    write(3, &amp;quot;00001299 0001 6167 __enter__ ret&amp;quot;..., 116) = 116
    write(3, &amp;quot;00001299 0001 6171 execute(&amp;#x27;sele&amp;quot;..., 82) = 82
    write(3, &amp;quot;Executing &amp;#x27;select tracer from tr&amp;quot;..., 68) = 68
    write(3, &amp;quot;self: &amp;lt;SqliteDb @0x7fa0feef9fd0 &amp;quot;..., 86) = 86
    fcntl(31, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = -1 EBADF (Bad file descriptor)
    open(&amp;quot;&amp;#x2F;home&amp;#x2F;travis&amp;#x2F;apprise-api&amp;#x2F;.coverage&amp;quot;, O_RDONLY|O_CLOEXEC) = 31
    fstat(31, {st_mode=S_IFREG|0644, st_size=192512, ...}) = 0
    ioctl(31, TCGETS, 0x7fff3bfa4920)       = -1 ENOTTY (Inappropriate ioctl for device)
    lseek(31, 0, SEEK_CUR)                  = 0
    read(31, &amp;quot;SQLite format 3\0\4\0\1\1\0@  \0\0\0\n\0\0\0\274&amp;quot;..., 4096) = 4096
    close(31)                               = 0
    write(3, &amp;quot;EXCEPTION from execute: disk I&amp;#x2F;O&amp;quot;..., 39) = 39
    write(3, &amp;quot;self: &amp;lt;SqliteDb @0x7fa0feef9fd0 &amp;quot;..., 86) = 86
    write(3, &amp;quot;00001299 0001 6172 __exit__(&amp;lt;cla&amp;quot;..., 208) = 208
    write(3, &amp;quot;00001299 0001 6173 close()\n&amp;quot;, 27) = 27
    fstat(31, 0x7fff3bfa4220)               = -1 EBADF (Bad file descriptor)
    close(31)                               = -1 EBADF (Bad file descriptor)
&lt;/code&gt;&lt;/pre&gt;
Notice the close(31) right after the lseek. This close(31) is not generated by SQLite; rather, it&amp;#x27;s being generated by the GC finalization of an unrelated file object:&lt;p&gt;&lt;pre&gt;&lt;code&gt;    #0  internal_close (self=&amp;lt;optimized out&amp;gt;) at .&amp;#x2F;Modules&amp;#x2F;_io&amp;#x2F;fileio.c:126
    #1  _io_FileIO_close_impl (self=&amp;lt;optimized out&amp;gt;) at .&amp;#x2F;Modules&amp;#x2F;_io&amp;#x2F;fileio.c:171
    #2  _io_FileIO_close (self=&amp;lt;optimized out&amp;gt;, _unused_ignored=&amp;lt;optimized out&amp;gt;) at .&amp;#x2F;Modules&amp;#x2F;_io&amp;#x2F;clinic&amp;#x2F;fileio.c.h:23
    #3  0x00007ffff7975be7 in _PyCFunction_FastCallDict (func_obj=func_obj@entry=0x7fffeefaee58, args=args@entry=0x7fffffff7590, nargs=0, kwargs=kwargs@entry=0x0) at Objects&amp;#x2F;methodobject.c:192
    #4  0x00007ffff791b89e in _PyObject_FastCallDict (func=func@entry=0x7fffeefaee58, args=args@entry=0x7fffffff7590, nargs=&amp;lt;optimized out&amp;gt;, kwargs=kwargs@entry=0x0) at Objects&amp;#x2F;abstract.c:2313
    #5  0x00007ffff791c8a4 in PyObject_CallMethodObjArgs (callable=0x7fffeefaee58, name=&amp;lt;optimized out&amp;gt;) at Objects&amp;#x2F;abstract.c:2759
    #6  0x00007ffff7a976b4 in buffered_close (self=0x7fffee02ae08, args=&amp;lt;optimized out&amp;gt;) at .&amp;#x2F;Modules&amp;#x2F;_io&amp;#x2F;bufferedio.c:538
    #7  0x00007ffff7975be7 in _PyCFunction_FastCallDict (func_obj=func_obj@entry=0x7fffedf7eab0, args=args@entry=0x7fffffff77c0, nargs=0, kwargs=kwargs@entry=0x0) at Objects&amp;#x2F;methodobject.c:192
    #8  0x00007ffff791b89e in _PyObject_FastCallDict (func=func@entry=0x7fffedf7eab0, args=args@entry=0x7fffffff77c0, nargs=&amp;lt;optimized out&amp;gt;, kwargs=kwargs@entry=0x0) at Objects&amp;#x2F;abstract.c:2313
    #9  0x00007ffff791c8a4 in PyObject_CallMethodObjArgs (callable=0x7fffedf7eab0, callable@entry=0x7fffee02ae08, name=&amp;lt;optimized out&amp;gt;) at Objects&amp;#x2F;abstract.c:2759
    #10 0x00007ffff7a90def in iobase_finalize (self=0x7fffee02ae08) at .&amp;#x2F;Modules&amp;#x2F;_io&amp;#x2F;iobase.c:266
    #11 0x00007ffff7a59e4f in finalize_garbage (collectable=0x7fffffff7950) at Modules&amp;#x2F;gcmodule.c:806
    #12 collect (generation=generation@entry=1, n_collected=n_collected@entry=0x7fffffff79f0, n_uncollectable=n_uncollectable@entry=0x7fffffff79f8, nofail=nofail@entry=0) at Modules&amp;#x2F;gcmodule.c:1005
    #13 0x00007ffff7a5a63b in collect_with_callback (generation=1) at Modules&amp;#x2F;gcmodule.c:1128
    #14 0x00007ffff7a5ae8b in collect_generations () at Modules&amp;#x2F;gcmodule.c:1151
    #15 _PyObject_GC_Alloc (basicsize=&amp;lt;optimized out&amp;gt;, use_calloc=0) at Modules&amp;#x2F;gcmodule.c:1729
    #16 _PyObject_GC_Malloc (basicsize=&amp;lt;optimized out&amp;gt;) at Modules&amp;#x2F;gcmodule.c:1739
    #17 0x00007ffff7a5afdd in _PyObject_GC_New (tp=tp@entry=0x7ffff7d53ea0 &amp;lt;PyGen_Type&amp;gt;) at Modules&amp;#x2F;gcmodule.c:1751
    #18 0x00007ffff794766f in gen_new_with_qualname (qualname=0x7ffff4c1b450, name=0x7ffff4c218f0, f=0x7ffff292daf8, type=0x7ffff7d53ea0 &amp;lt;PyGen_Type&amp;gt;) at Objects&amp;#x2F;genobject.c:802
    #19 PyGen_NewWithQualName (f=0x7ffff292daf8, name=0x7ffff4c218f0, qualname=0x7ffff4c1b450) at Objects&amp;#x2F;genobject.c:830
    #20 0x00007ffff7a07f31 in _PyEval_EvalCodeWithName (_co=0x7ffff4c23270, globals=globals@entry=0x7ffff4cdd9d8, locals=locals@entry=0x0, args=&amp;lt;optimized out&amp;gt;, argcount=1, kwnames=kwnames@entry=0x0, kwargs=0x7ffff4c32930, 
        kwcount=0, kwstep=1, defs=0x0, defcount=0, kwdefs=0x0, closure=0x7fffede2cfd0, name=0x7ffff4c218f0, qualname=0x7ffff4c1b450) at Python&amp;#x2F;ceval.c:4150
    #21 0x00007ffff7a081d7 in fast_function (kwnames=0x0, nargs=&amp;lt;optimized out&amp;gt;, stack=&amp;lt;optimized out&amp;gt;, func=0x7fffedc03f28) at Python&amp;#x2F;ceval.c:4978
    #22 call_function (pp_stack=pp_stack@entry=0x7fffffff7c60, oparg=oparg@entry=1, kwnames=kwnames@entry=0x0) at Python&amp;#x2F;ceval.c:4858
    #23 0x00007ffff7a0a633 in _PyEval_EvalFrameDefault (f=&amp;lt;optimized out&amp;gt;, throwflag=&amp;lt;optimized out&amp;gt;) at Python&amp;#x2F;ceval.c:3335
&lt;/code&gt;&lt;/pre&gt;
Note that normal SQLite3 closes look like this:&lt;p&gt;&lt;pre&gt;&lt;code&gt;    #0  0x00007ffff769b560 in __close_nocancel () from &amp;#x2F;lib&amp;#x2F;x86_64-linux-gnu&amp;#x2F;libpthread.so.0
    #1  0x00007ffff3a23d8c in robust_close (lineno=29378, h=&amp;lt;optimized out&amp;gt;, pFile=0x113cfd8) at sqlite3.c:28631
    #2  closeUnixFile (id=id@entry=0x113cfd8) at sqlite3.c:29378
    #3  0x00007ffff3a24f43 in unixClose (id=0x113cfd8) at sqlite3.c:29427
    #4  0x00007ffff3a4858b in sqlite3OsClose (pId=0x113cfd8) at sqlite3.c:17944
    #5  sqlite3PagerClose (pPager=0x113ce68) at sqlite3.c:47961
    #6  0x00007ffff3a5930b in sqlite3BtreeClose (p=0xfb8088) at sqlite3.c:58266
    #7  0x00007ffff3a59501 in sqlite3LeaveMutexAndCloseZombie (db=0x1260598) at sqlite3.c:134102
    #8  0x00007ffff3a59ae2 in sqlite3Close (db=0x1260598, forceZombie=0) at sqlite3.c:134045
    #9  0x00007ffff3cc8fe2 in pysqlite_connection_close (self=0x7fffedf5fd50, args=&amp;lt;optimized out&amp;gt;) at &amp;#x2F;tmp&amp;#x2F;python-build.20181021062245.3423&amp;#x2F;Python-3.6.7&amp;#x2F;Modules&amp;#x2F;_sqlite&amp;#x2F;connection.c:337
    #10 0x00007ffff7975be7 in _PyCFunction_FastCallDict (func_obj=0x7fffedf7eab0, args=0x7fffede2e890, nargs=0, kwargs=kwargs@entry=0x0) at Objects&amp;#x2F;methodobject.c:192
    #11 0x00007ffff7975eb7 in _PyCFunction_FastCallKeywords (func=func@entry=0x7fffedf7eab0, stack=stack@entry=0x7fffede2e890, nargs=&amp;lt;optimized out&amp;gt;, kwnames=kwnames@entry=0x0) at Objects&amp;#x2F;methodobject.c:294
    #12 0x00007ffff7a082c1 in call_function (pp_stack=pp_stack@entry=0x7fffffff9640, oparg=oparg@entry=0, kwnames=kwnames@entry=0x0) at Python&amp;#x2F;ceval.c:4837
&lt;/code&gt;&lt;/pre&gt;
EDIT 1: OK, I found the line of code that allocates this file, at line 398 in apprise_api&amp;#x2F;api&amp;#x2F;views.py:&lt;p&gt;&lt;pre&gt;&lt;code&gt;             with NamedTemporaryFile() as f:
                # Write our content to disk
                f.write(config.encode())
                f.flush()
&lt;/code&gt;&lt;/pre&gt;
If you disable this block of code everything runs fine (although the tests fail). It&amp;#x27;s kinda creepy that the NamedTemporaryFile is leaking - it really shouldn&amp;#x27;t...</text></comment>
<story><title>Bug #915: Please help</title><url>https://nedbatchelder.com/blog/202001/bug_915_please_help.html</url></story><parent_chain></parent_chain><comment><author>tyingq</author><text>Unfortunately, the sqlite3 python interface doesn&amp;#x27;t expose Sqlite&amp;#x27;s extended error info so that you could see what&amp;#x27;s happening.&lt;p&gt;&lt;a href=&quot;https:&amp;#x2F;&amp;#x2F;bugs.python.org&amp;#x2F;issue16379&quot; rel=&quot;nofollow&quot;&gt;https:&amp;#x2F;&amp;#x2F;bugs.python.org&amp;#x2F;issue16379&lt;/a&gt;&lt;p&gt;There an uncommitted patch to get the extended error in this other, related issue: &lt;a href=&quot;https:&amp;#x2F;&amp;#x2F;bugs.python.org&amp;#x2F;issue24139&quot; rel=&quot;nofollow&quot;&gt;https:&amp;#x2F;&amp;#x2F;bugs.python.org&amp;#x2F;issue24139&lt;/a&gt;&lt;p&gt;Or maybe just try cffi or ctypes in python to call sqlite3_errcode(), sqlite3_extended_errcode() and sqlite3_errmsg().  The incantation to find an already linked sqlite3 lib:&lt;p&gt;import ctypes&lt;p&gt;import ctypes.util&lt;p&gt;sqlite = ctypes.CDLL(ctypes.util.find_library(&amp;#x27;sqlite3&amp;#x27;))</text></comment>