Have os_unix.c call sqlite3_log() following errors in certain system calls.

FossilOrigin-Name: 01076528a43b61ae20ef6969b7d326de9b5313e4

manifest

@@ -1,8 +1,5 @@
------BEGIN PGP SIGNED MESSAGE-----
+C Have\sos_unix.c\scall\ssqlite3_log()\sfollowing\serrors\sin\scertain\ssystem\scalls.
-Hash: SHA1
+D 2011-02-21T11:46:24
-
-C An\sSQLITE_PROTOCOL\serror\scounts\sas\sa\slocking\serror\sfor\sverification\npurposes.
-D 2011-02-19T23:18:12.968
 F Makefile.arm-wince-mingw32ce-gcc d6df77f1f48d690bd73162294bbba7f59507c72f
 F Makefile.in 27701a1653595a1f2187dc61c8117e00a6c1d50f
 F Makefile.linux-gcc 91d710bdc4998cb015f39edf3cb314ec4f4d7e23
@@ -164,7 +161,7 @@ F src/os.c 22ac61d06e72a0dac900400147333b07b13d8e1d
 F src/os.h 9dbed8c2b9c1f2f2ebabc09e49829d4777c26bf9
 F src/os_common.h a8f95b81eca8a1ab8593d23e94f8a35f35d4078f
 F src/os_os2.c 2e452c9f2ca507623ad351c33a8a8b27849b1863
-F src/os_unix.c 1be46a35bad4bec5171e4de88aaff817260eb378
+F src/os_unix.c 0969a5921f2ff2a54c53d9b76eba9e4190ae9001
 F src/os_win.c 9abdcdd925416d854eabb0996c96debd92abfef5
 F src/pager.c d62dfc1d77168c4415e7f3e23c6dbee4f3fdff60
 F src/pager.h 3f8c783de1d4706b40b1ac15b64f5f896bcc78d1
@@ -585,6 +582,7 @@ F test/notify3.test d60923e186e0900f4812a845fcdfd8eea096e33a
 F test/notnull.test cc7c78340328e6112a13c3e311a9ab3127114347
 F test/null.test a8b09b8ed87852742343b33441a9240022108993
 F test/openv2.test af02ed0a9cbc0d2a61b8f35171d4d117e588e4ec
+F test/oserror.test 5775264a41039856d211168713d916949227fedd
 F test/pager1.test d8672fd0af5f4f9b99b06283d00f01547809bebe
 F test/pager2.test 745b911dde3d1f24ae0870bd433dfa83d7c658c1
 F test/pager3.test 3856d9c80839be0668efee1b74811b1b7f7fc95f
@@ -910,14 +908,7 @@ F tool/speedtest2.tcl ee2149167303ba8e95af97873c575c3e0fab58ff
 F tool/speedtest8.c 2902c46588c40b55661e471d7a86e4dd71a18224
 F tool/speedtest8inst1.c 293327bc76823f473684d589a8160bde1f52c14e
 F tool/vdbe-compress.tcl d70ea6d8a19e3571d7ab8c9b75cba86d1173ff0f
-P 6f3dad32aa0e1e9ee374302c82bea9bd60d5854b
+P e87d499a4f8a456111c1f96ca6da31d0810fb7c8
-R 86390ecedcedb59a969c739855db603c
+R fd86ed6c132ac26057f4026c493ad018
-U drh
+U dan
-Z 0eda2ef2b7ac0ef88e60eb9b30b8c952
+Z 2bb27580b8cb6c1cd91c27a584f12f47
------BEGIN PGP SIGNATURE-----
-Version: GnuPG v1.4.6 (GNU/Linux)
-
-iD8DBQFNYE+4oxKgR168RlERAmPGAJ4rDJ23k3TF0EXjOGmea9Lr0wfA5ACgidUP
-oQjTQQmYRNZjbFBXU3DJWCg=
-=FnVe
------END PGP SIGNATURE-----

manifest.uuid

@@ -1 +1 @@
-e87d499a4f8a456111c1f96ca6da31d0810fb7c8
+01076528a43b61ae20ef6969b7d326de9b5313e4

src/os_unix.c

@@ -738,6 +738,75 @@ struct unixInodeInfo {
 */
 static unixInodeInfo *inodeList = 0;
 
+/*
+**
+** This function - unixLogError_x(), is only ever called via the macro
+** unixLogError().
+**
+** It is invoked after an error occurs in an OS function and errno has been
+** set. It logs a message using sqlite3_log() containing the current value of
+** errno and, if possible, the human-readable equivalent from strerror() or
+** strerror_r().
+**
+** The first argument passed to the macro should be the error code that
+** will be returned to SQLite (e.g. SQLITE_IOERR_DELETE, SQLITE_CANTOPEN). 
+** The two subsequent arguments should be the name of the OS function that
+** failed (e.g. "unlink", "open") and the the associated file-system path,
+** if any.
+*/
+#define unixLogError(a,b,c)     unixLogError_x(a,b,c,__LINE__)
+static int unixLogError_x(
+  int errcode,                    /* SQLite error code */
+  const char *zFunc,              /* Name of OS function that failed */
+  const char *zPath,              /* File path associated with error */
+  int iLine                       /* Source line number where error occurred */
+){
+  char *zErr;                     /* Message from strerror() or equivalent */
+
+  /* If this is not a threadsafe build (SQLITE_THREADSAFE==0), then use
+  ** the strerror() function to obtain the human-readable error message
+  ** equivalent to errno. Otherwise, use strerror_r().
+  */ 
+#if SQLITE_THREADSAFE && defined(HAVE_STRERROR_R)
+  char aErr[80];
+  memset(aErr, 0, sizeof(aErr));
+  zErr = aErr;
+
+  /* If STRERROR_R_CHAR_P (set by autoconf scripts) or __USE_GNU is defined,
+  ** assume that the system provides the the GNU version of strerror_r() that 
+  ** returns a pointer to a buffer containing the error message. That pointer 
+  ** may point to aErr[], or it may point to some static storage somewhere. 
+  ** Otherwise, assume that the system provides the POSIX version of 
+  ** strerror_r(), which always writes an error message into aErr[].
+  **
+  ** If the code incorrectly assumes that it is the POSIX version that is
+  ** available, the error message will often be an empty string. Not a
+  ** huge problem. Incorrectly concluding that the GNU version is available 
+  ** could lead to a segfault though.
+  */
+#if defined(STRERROR_R_CHAR_P) || defined(__USE_GNU)
+  zErr = 
+# endif
+  strerror_r(errno, aErr, sizeof(aErr)-1);
+
+#elif SQLITE_THREADSAFE
+  /* This is a threadsafe build, but strerror_r() is not available. */
+  zErr = "";
+#else
+  /* Non-threadsafe build, use strerror(). */
+  zErr = strerror(errno);
+#endif
+
+  assert( errcode!=SQLITE_OK );
+  sqlite3_log(errcode,
+      "os_unix.c: %s() at line %d - \"%s\" errno=%d path=%s",
+      zFunc, iLine, zErr, errno, (zPath ? zPath : "n/a")
+  );
+
+  return errcode;
+}
+
+
 /*
 ** Close all file descriptors accumuated in the unixInodeInfo->pUnused list.
 ** If all such file descriptors are closed without error, the list is
@@ -757,7 +826,7 @@ static int closePendingFds(unixFile *pFile){
     pNext = p->pNext;
     if( close(p->fd) ){
       pFile->lastErrno = errno;
-      rc = SQLITE_IOERR_CLOSE;
+      rc = unixLogError(SQLITE_IOERR_CLOSE, "close", pFile->zPath);
       p->pNext = pError;
       pError = p;
     }else{
@@ -1410,7 +1479,7 @@ static int closeUnixFile(sqlite3_file *id){
       int err = close(pFile->dirfd);
       if( err ){
         pFile->lastErrno = errno;
-        return SQLITE_IOERR_DIR_CLOSE;
+        return unixLogError(SQLITE_IOERR_DIR_CLOSE, "close", pFile->zPath);
       }else{
         pFile->dirfd=-1;
       }
@@ -1419,7 +1488,7 @@ static int closeUnixFile(sqlite3_file *id){
       int err = close(pFile->h);
       if( err ){
         pFile->lastErrno = errno;
-        return SQLITE_IOERR_CLOSE;
+        return unixLogError(SQLITE_IOERR_CLOSE, "close", pFile->zPath);
       }
     }
 #if OS_VXWORKS
@@ -2941,7 +3010,7 @@ static int unixSync(sqlite3_file *id, int flags){
   SimulateIOError( rc=1 );
   if( rc ){
     pFile->lastErrno = errno;
-    return SQLITE_IOERR_FSYNC;
+    return unixLogError(SQLITE_IOERR_FSYNC, "full_fsync", pFile->zPath);
   }
   if( pFile->dirfd>=0 ){
     int err;
@@ -2968,7 +3037,7 @@ static int unixSync(sqlite3_file *id, int flags){
       pFile->dirfd = -1;
     }else{
       pFile->lastErrno = errno;
-      rc = SQLITE_IOERR_DIR_CLOSE;
+      rc = unixLogError(SQLITE_IOERR_DIR_CLOSE, "close", pFile->zPath);
     }
   }
   return rc;
@@ -2995,7 +3064,7 @@ static int unixTruncate(sqlite3_file *id, i64 nByte){
   rc = ftruncate(pFile->h, (off_t)nByte);
   if( rc ){
     pFile->lastErrno = errno;
-    return SQLITE_IOERR_TRUNCATE;
+    return unixLogError(SQLITE_IOERR_TRUNCATE, "ftruncate", pFile->zPath);
   }else{
 #ifndef NDEBUG
     /* If we are doing a normal write to a database file (as opposed to
@@ -3083,7 +3152,7 @@ static int fcntlSizeHint(unixFile *pFile, i64 nByte){
 
       if( ftruncate(pFile->h, nSize) ){
         pFile->lastErrno = errno;
-        return SQLITE_IOERR_TRUNCATE;
+        return unixLogError(SQLITE_IOERR_TRUNCATE, "ftruncate", pFile->zPath);
       }
       iWrite = ((buf.st_size + 2*nBlk - 1)/nBlk)*nBlk-1;
       do {
@@ -3432,7 +3501,7 @@ static int unixOpenSharedMemory(unixFile *pDbFd){
 
     pShmNode->h = open(zShmFilename, O_RDWR|O_CREAT, (sStat.st_mode & 0777));
     if( pShmNode->h<0 ){
-      rc = SQLITE_CANTOPEN_BKPT;
+      rc = unixLogError(SQLITE_CANTOPEN_BKPT, "open", zShmFilename);
       goto shm_open_err;
     }
 
@@ -3442,7 +3511,7 @@ static int unixOpenSharedMemory(unixFile *pDbFd){
     rc = SQLITE_OK;
     if( unixShmSystemLock(pShmNode, F_WRLCK, UNIX_SHM_DMS, 1)==SQLITE_OK ){
       if( ftruncate(pShmNode->h, 0) ){
-        rc = SQLITE_IOERR_SHMOPEN;
+        rc = unixLogError(SQLITE_IOERR_SHMOPEN, "ftruncate", zShmFilename);
       }
     }
     if( rc==SQLITE_OK ){
@@ -3548,7 +3617,7 @@ static int unixShmMap(
       */
       if( !bExtend ) goto shmpage_out;
       if( ftruncate(pShmNode->h, nByte) ){
-        rc = SQLITE_IOERR_SHMSIZE;
+        rc = unixLogError(SQLITE_IOERR_SHMSIZE,"ftruncate",pShmNode->zFilename);
         goto shmpage_out;
       }
     }
@@ -4267,7 +4336,7 @@ static int openDirectory(const char *zFilename, int *pFd){
     }
   }
   *pFd = fd;
-  return (fd>=0?SQLITE_OK:SQLITE_CANTOPEN_BKPT);
+  return (fd>=0?SQLITE_OK:unixLogError(SQLITE_CANTOPEN_BKPT, "open", zDirname));
 }
 
 /*
@@ -4608,7 +4677,7 @@ static int unixOpen(
       fd = open(zName, openFlags, openMode);
     }
     if( fd<0 ){
-      rc = SQLITE_CANTOPEN_BKPT;
+      rc = unixLogError(SQLITE_CANTOPEN_BKPT, "open", zName);
       goto open_finished;
     }
   }
@@ -4740,7 +4809,7 @@ static int unixDelete(
   UNUSED_PARAMETER(NotUsed);
   SimulateIOError(return SQLITE_IOERR_DELETE);
   if( unlink(zPath)==(-1) && errno!=ENOENT ){
-    return SQLITE_IOERR_DELETE;
+    return unixLogError(SQLITE_IOERR_DELETE, "unlink", zPath);
   }
 #ifndef SQLITE_DISABLE_DIRSYNC
   if( dirSync ){
@@ -4753,10 +4822,10 @@ static int unixDelete(
       if( fsync(fd) )
 #endif
       {
-        rc = SQLITE_IOERR_DIR_FSYNC;
+        rc = unixLogError(SQLITE_IOERR_DIR_FSYNC, "fsync", zPath);
       }
       if( close(fd)&&!rc ){
-        rc = SQLITE_IOERR_DIR_CLOSE;
+        rc = unixLogError(SQLITE_IOERR_DIR_CLOSE, "close", zPath);
       }
     }
   }
@@ -4840,7 +4909,7 @@ static int unixFullPathname(
   }else{
     int nCwd;
     if( getcwd(zOut, nOut-1)==0 ){
-      return SQLITE_CANTOPEN_BKPT;
+      return unixLogError(SQLITE_CANTOPEN_BKPT, "getcwd", zPath);
     }
     nCwd = (int)strlen(zOut);
     sqlite3_snprintf(nOut-nCwd, &zOut[nCwd], "/%s", zPath);

test/oserror.test

@@ -0,0 +1,112 @@
+# 2011 February 19
+#
+# The author disclaims copyright to this source code.  In place of
+# a legal notice, here is a blessing:
+#
+#    May you do good and not evil.
+#    May you find forgiveness for yourself and forgive others.
+#    May you share freely, never taking more than you give.
+#
+#***********************************************************************
+# This file implements regression tests for SQLite library.  The
+# focus of this file is testing that error messages are logged via the
+# sqlite3_log() mechanism when certain errors are encountered in the
+# default unix or windows VFS modules.
+#
+
+set testdir [file dirname $argv0]
+source $testdir/tester.tcl
+if {$::tcl_platform(platform)!="unix"} { finish_test ; return }
+set ::testprefix oserror
+
+db close
+sqlite3_shutdown
+test_sqlite3_log xLog
+proc xLog {error_code msg} {
+  if {[string match os_* $msg]} {
+    lappend ::log $msg 
+  }
+}
+
+proc do_re_test {tn script expression} {
+  uplevel do_test $tn [list [subst -nocommands {
+    set res [eval { $script }]
+    if {[regexp {$expression} [set res]]} {
+      set {} {$expression}
+    } else {
+      set res
+    }
+  }]] [list $expression]
+  
+}
+
+#--------------------------------------------------------------------------
+# Tests oserror-1.* test failures in the open() system call.
+#
+
+# Test a failure in open() due to too many files.
+#
+do_test 1.1.1 {
+  set ::log [list]
+  list [catch {
+    for {set i 0} {$i < 2000} {incr i} { sqlite3 dbh_$i test.db -readonly 1 }
+  } msg] $msg
+} {1 {unable to open database file}}
+do_test 1.1.2 {
+  catch { for {set i 0} {$i < 2000} {incr i} { dbh_$i close } }
+} {1}
+
+do_re_test 1.1.3 { lindex $::log 0 } {^os_unix.c: open.*test.db$}
+
+
+# Test a failure in open() due to the path being a directory.
+#
+do_test 1.2.1 {
+  file mkdir dir.db
+  set ::log [list]
+  list [catch { sqlite3 dbh dir.db } msg] $msg
+} {1 {unable to open database file}}
+
+do_re_test 1.2.2 { lindex $::log 0 } {^os_unix.c: open.*dir.db$}
+
+# Test a failure in open() due to the path not existing.
+#
+do_test 1.3.1 {
+  set ::log [list]
+  list [catch { sqlite3 dbh /x/y/z/test.db } msg] $msg
+} {1 {unable to open database file}}
+
+do_re_test 1.3.2 { lindex $::log 0 } {^os_unix.c: open.*test.db$}
+
+# Test a failure in open() due to the path not existing.
+#
+do_test 1.4.1 {
+  set ::log [list]
+  list [catch { sqlite3 dbh /root/test.db } msg] $msg
+} {1 {unable to open database file}}
+
+do_re_test 1.4.2 { lindex $::log 0 } {^os_unix.c: open.*test.db$}
+
+#--------------------------------------------------------------------------
+# Tests oserror-1.* test failures in the unlink() system call.
+#
+do_test 2.1.1 {
+  set ::log [list]
+  file mkdir test.db-wal
+  forcedelete test.db
+  sqlite3 dbh test.db
+  catchsql { SELECT * FROM sqlite_master } dbh
+} {1 {disk I/O error}}
+
+do_re_test 2.1.2 { lindex $::log 0 } {^os_unix.c: unlink.*test.db-wal$}
+do_test 2.1.3 { 
+  dbh close
+  forcedelete test.db-wal
+} {}
+  
+
+sqlite3_shutdown
+test_sqlite3_log 
+sqlite3_initialize
+finish_test
+