1From 75598d83216e61989af3e73af0e131593568a395 Mon Sep 17 00:00:00 2001 2From: MartinChoo <214582617@qq.com> 3Date: Wed, 23 Jul 2025 17:39:54 +0800 4Subject: [PATCH 03/12] Busy debug and log dump 5 6--- 7 src/sqlite3.c | 745 +++++++++++++++++++++++++++++++++++++++++++++++++- 8 1 file changed, 731 insertions(+), 14 deletions(-) 9 10diff --git a/src/sqlite3.c b/src/sqlite3.c 11index efc4cd4..6f423a9 100644 12--- a/src/sqlite3.c 13+++ b/src/sqlite3.c 14@@ -879,6 +879,7 @@ SQLITE_API int sqlite3_exec( 15 #define SQLITE_NOTICE_RECOVER_ROLLBACK (SQLITE_NOTICE | (2<<8)) 16 #define SQLITE_NOTICE_RBU (SQLITE_NOTICE | (3<<8)) 17 #define SQLITE_WARNING_AUTOINDEX (SQLITE_WARNING | (1<<8)) 18+#define SQLITE_WARNING_DUMP (SQLITE_WARNING | (2<<8)) 19 #define SQLITE_AUTH_USER (SQLITE_AUTH | (1<<8)) 20 #define SQLITE_OK_LOAD_PERMANENTLY (SQLITE_OK | (1<<8)) 21 #define SQLITE_OK_SYMLINK (SQLITE_OK | (2<<8)) /* internal use only */ 22@@ -21831,6 +21832,10 @@ SQLITE_API extern int sqlite3_open_file_count; 23 #define OpenCounter(X) 24 #endif /* defined(SQLITE_TEST) */ 25 26+#ifdef FDSAN_ENABLE 27+#define SQLITE_FDSAN_TAG 5351 28+#endif /* FDSAN_ENABLE */ 29+ 30 #endif /* !defined(_OS_COMMON_H_) */ 31 32 /************** End of os_common.h *******************************************/ 33@@ -32201,7 +32206,11 @@ SQLITE_API char *sqlite3_snprintf(int n, char *zBuf, const char *zFormat, ...){ 34 */ 35 static void renderLogMsg(int iErrCode, const char *zFormat, va_list ap){ 36 StrAccum acc; /* String accumulator */ 37+#ifndef LOG_DUMP 38 char zMsg[SQLITE_PRINT_BUF_SIZE*3]; /* Complete log message */ 39+#else 40+ char zMsg[SQLITE_PRINT_BUF_SIZE*10]; /* Complete log message */ 41+#endif /* !LOG_DUMP */ 42 43 sqlite3StrAccumInit(&acc, 0, zMsg, sizeof(zMsg), 0); 44 sqlite3_str_vappendf(&acc, zFormat, ap); 45@@ -38026,6 +38035,45 @@ SQLITE_PRIVATE int sqlite3KvvfsInit(void){ 46 #endif 47 48 /************** End of os_kv.c ***********************************************/ 49+/************** Define dump function *****************************************/ 50+#if SQLITE_OS_UNIX 51+#define DB_LOCK_NUM 3 52+#define WAL_LOCK_NUM 9 53+// 8 wal lock, 1 SHM_DMS lock, 1 TRX lock 54+#define MAX_LOCK_NUM (WAL_LOCK_NUM + 1) 55+#define SHM_DMS_IDX (WAL_LOCK_NUM - 1) 56+#define TRX_LOCK_IDX WAL_LOCK_NUM 57+#define LOCK_BY_PROCESS 1 58+#define LOCK_BY_THREAD 0 59+#define DUMP_BUF_MAX_LEN 180 60+#define DUMP_MAX_STR_LEN 21 61+ 62+typedef struct LocalLockStatus { 63+ u8 busyLockIdx; 64+ u8 busyLockType; 65+ u8 lockByProcess; 66+ u8 reserved; 67+ u32 lockLen; 68+ u32 busyLine; 69+ int curTid; 70+ u8 lockStatus[MAX_LOCK_NUM]; // last index is trx lock 71+} LocalLockStatus; 72+__thread LocalLockStatus g_lockStatus = {0}; 73+ 74+#define MARK_LAST_BUSY_LINE(rc) {if ((rc)==SQLITE_BUSY || (rc) == SQLITE_LOCKED) g_lockStatus.busyLine = __LINE__;} 75+static void ResetLockStatus(void); 76+static void TryRecordTid(int *tidBuf, int ofs, int lockLen); 77+static void TryClearTid(int *tidBuf, int ofs, int lockLen); 78+static void MarkLockBusy(u32 lockIdx, u32 lockLen, u8 lockType, u8 lockByProcess); 79+static void MarkLockStatus(u32 lockIdx, u32 lockLen, u8 lockType); 80+static void MarkLockStatusByRc(int rc, u32 lockIdx, u32 lockLen, u8 lockType, u8 lockByProcess); 81+#else 82+#define MARK_LAST_BUSY_LINE(rc) 83+#define ResetLockStatus(void) 84+#define MarkLockBusy(A, B, C, D) 85+#define MarkLockStatusByRc(A, B, C, D, E) 86+#endif 87+/************** End define dump function *************************************/ 88 /************** Begin file os_unix.c *****************************************/ 89 /* 90 ** 2004 May 22 91@@ -38425,6 +38473,29 @@ static pid_t randomnessPid = 0; 92 #define F2FS_FEATURE_ATOMIC_WRITE 0x0004 93 #endif /* __linux__ */ 94 95+#ifdef OS_FEATURE 96+#define HMFS_MONITOR_FL 0x00000002 97+#define HMFS_IOCTL_HW_GET_FLAGS _IOR(0xf5, 70, unsigned int) 98+#define HMFS_IOCTL_HW_SET_FLAGS _IOR(0xf5, 71, unsigned int) 99+ 100+static void enableDbFileDelMonitor(int32_t fd) 101+{ 102+ unsigned int flags = 0; 103+ int ret = ioctl(fd, HMFS_IOCTL_HW_GET_FLAGS, &flags); 104+ if (ret < 0) { 105+ return; 106+ } 107+ if (flags & HMFS_MONITOR_FL) { 108+ return; 109+ } 110+ flags |= HMFS_MONITOR_FL; 111+ ret = ioctl(fd, HMFS_IOCTL_HW_SET_FLAGS, &flags); 112+ if (ret < 0) { 113+ sqlite3_log(SQLITE_WARNING, "Fd %d enable del monitor go wrong, errno = %d", fd, errno); 114+ } 115+} 116+ 117+#endif /* OS_FEATURE */ 118 119 /* 120 ** Different Unix systems declare open() in different ways. Same use 121@@ -38435,7 +38506,29 @@ static pid_t randomnessPid = 0; 122 ** which always has the same well-defined interface. 123 */ 124 static int posixOpen(const char *zFile, int flags, int mode){ 125- return open(zFile, flags, mode); 126+ int fd = open(zFile, flags, mode); 127+#ifdef FDSAN_ENABLE 128+ if( fd >= 0 ){ 129+ fdsan_exchange_owner_tag(fd, 0, fdsan_create_owner_tag(FDSAN_OWNER_TYPE_FILE, SQLITE_FDSAN_TAG)); 130+ } 131+#endif /* FDSAN_ENABLE */ 132+#ifdef OS_FEATURE 133+ if( fd >= 0 ){ 134+ enableDbFileDelMonitor(fd); 135+ } 136+#endif /* OS_FEATURE */ 137+ return fd; 138+} 139+ 140+/* 141+** Change close to posixClose, use fdsan_close_with_tag when fdsan enable. 142+*/ 143+static int posixClose(int fd) { 144+#ifdef FDSAN_ENABLE 145+ return fdsan_close_with_tag(fd, fdsan_create_owner_tag(FDSAN_OWNER_TYPE_FILE, SQLITE_FDSAN_TAG)); 146+#else 147+ return close(fd); 148+#endif /* FDSAN_ENABLE */ 149 } 150 151 /* Forward reference */ 152@@ -38456,7 +38549,7 @@ static struct unix_syscall { 153 { "open", (sqlite3_syscall_ptr)posixOpen, 0 }, 154 #define osOpen ((int(*)(const char*,int,int))aSyscall[0].pCurrent) 155 156- { "close", (sqlite3_syscall_ptr)close, 0 }, 157+ { "close", (sqlite3_syscall_ptr)posixClose, 0 }, 158 #define osClose ((int(*)(int))aSyscall[1].pCurrent) 159 160 { "access", (sqlite3_syscall_ptr)access, 0 }, 161@@ -39456,6 +39549,9 @@ static int findInodeInfo( 162 #if defined(EOVERFLOW) && defined(SQLITE_DISABLE_LFS) 163 if( pFile->lastErrno==EOVERFLOW ) return SQLITE_NOLFS; 164 #endif 165+#ifdef LOG_DUMP 166+ sqlite3_log(SQLITE_IOERR, "findInodeInfo-osFstat, fd[%d], errno[%d], osFstat[%d]", fd, errno, rc); 167+#endif /* LOG_DUMP */ 168 return SQLITE_IOERR; 169 } 170 171@@ -39474,11 +39570,17 @@ static int findInodeInfo( 172 do{ rc = osWrite(fd, "S", 1); }while( rc<0 && errno==EINTR ); 173 if( rc!=1 ){ 174 storeLastErrno(pFile, errno); 175+#ifdef LOG_DUMP 176+ sqlite3_log(SQLITE_IOERR, "findInodeInfo-osWrite, fd[%d], errno[%d], osFstat[%d]", fd, errno, rc); 177+#endif /* LOG_DUMP */ 178 return SQLITE_IOERR; 179 } 180 rc = osFstat(fd, &statbuf); 181 if( rc!=0 ){ 182 storeLastErrno(pFile, errno); 183+#ifdef LOG_DUMP 184+ sqlite3_log(SQLITE_IOERR, "findInodeInfo-msdos-osFstat, fd[%d], errno[%d], osFstat[%d]", fd, errno, rc); 185+#endif /* LOG_DUMP */ 186 return SQLITE_IOERR; 187 } 188 } 189@@ -39791,6 +39893,7 @@ static int unixLock(sqlite3_file *id, int eFileLock){ 190 if( pFile->eFileLock>=eFileLock ){ 191 OSTRACE(("LOCK %d %s ok (already held) (unix)\n", pFile->h, 192 azFileLock(eFileLock))); 193+ MarkLockStatus(TRX_LOCK_IDX, 1, eFileLock); 194 return SQLITE_OK; 195 } 196 197@@ -39815,6 +39918,7 @@ static int unixLock(sqlite3_file *id, int eFileLock){ 198 (pInode->eFileLock>=PENDING_LOCK || eFileLock>SHARED_LOCK)) 199 ){ 200 rc = SQLITE_BUSY; 201+ MarkLockBusy(TRX_LOCK_IDX, 1, eFileLock, LOCK_BY_THREAD); 202 goto end_lock; 203 } 204 205@@ -39830,6 +39934,7 @@ static int unixLock(sqlite3_file *id, int eFileLock){ 206 pFile->eFileLock = SHARED_LOCK; 207 pInode->nShared++; 208 pInode->nLock++; 209+ MarkLockStatus(TRX_LOCK_IDX, 1, eFileLock); 210 goto end_lock; 211 } 212 213@@ -39851,6 +39956,7 @@ static int unixLock(sqlite3_file *id, int eFileLock){ 214 if( rc!=SQLITE_BUSY ){ 215 storeLastErrno(pFile, tErrno); 216 } 217+ MarkLockStatusByRc(rc, TRX_LOCK_IDX, 1, SHARED_LOCK, LOCK_BY_PROCESS); 218 goto end_lock; 219 }else if( eFileLock==EXCLUSIVE_LOCK ){ 220 pFile->eFileLock = PENDING_LOCK; 221@@ -39874,7 +39980,7 @@ static int unixLock(sqlite3_file *id, int eFileLock){ 222 tErrno = errno; 223 rc = sqliteErrorFromPosixError(tErrno, SQLITE_IOERR_LOCK); 224 } 225- 226+ MarkLockStatusByRc(rc, TRX_LOCK_IDX, 1, SHARED_LOCK, LOCK_BY_PROCESS); 227 /* Drop the temporary PENDING lock */ 228 lock.l_start = PENDING_BYTE; 229 lock.l_len = 1L; 230@@ -39899,6 +40005,7 @@ static int unixLock(sqlite3_file *id, int eFileLock){ 231 /* We are trying for an exclusive lock but another thread in this 232 ** same process is still holding a shared lock. */ 233 rc = SQLITE_BUSY; 234+ MarkLockBusy(TRX_LOCK_IDX, 1, eFileLock, LOCK_BY_THREAD); 235 }else{ 236 /* The request was for a RESERVED or EXCLUSIVE lock. It is 237 ** assumed that there is a SHARED or greater lock on the file 238@@ -39923,6 +40030,7 @@ static int unixLock(sqlite3_file *id, int eFileLock){ 239 storeLastErrno(pFile, tErrno); 240 } 241 } 242+ MarkLockStatusByRc(rc, TRX_LOCK_IDX, 1, eFileLock, LOCK_BY_PROCESS); 243 } 244 245 246@@ -40640,6 +40748,9 @@ static int flockUnlock(sqlite3_file *id, int eFileLock) { 247 #ifdef SQLITE_IGNORE_FLOCK_LOCK_ERRORS 248 return SQLITE_OK; 249 #endif /* SQLITE_IGNORE_FLOCK_LOCK_ERRORS */ 250+#ifdef LOG_DUMP 251+ sqlite3_log(SQLITE_IOERR_UNLOCK, "IOERR_UNLOCK fd[%d], eFileLock[%d]", pFile->h, eFileLock); 252+#endif /* LOG_DUMP */ 253 return SQLITE_IOERR_UNLOCK; 254 }else{ 255 pFile->eFileLock = NO_LOCK; 256@@ -41452,8 +41563,14 @@ static int unixRead( 257 #ifdef EDEVERR 258 case EDEVERR: 259 #endif 260+#ifdef LOG_DUMP 261+ sqlite3_log(SQLITE_IOERR_CORRUPTFS, "unixRead-EDEVERR, fd:[%d], amt[%d], got[%d], offset[%lld]", pFile->h, amt, got, offset); 262+#endif /* LOG_DUMP */ 263 return SQLITE_IOERR_CORRUPTFS; 264 } 265+#ifdef LOG_DUMP 266+ sqlite3_log(SQLITE_IOERR_READ, "unixRead-got<0, fd: [%d], amt[%d], got[%d], offset[%lld]", pFile->h, amt, got, offset); 267+#endif /* LOG_DUMP */ 268 return SQLITE_IOERR_READ; 269 }else{ 270 storeLastErrno(pFile, 0); /* not a system error */ 271@@ -41595,9 +41712,19 @@ static int unixWrite( 272 if( amt>wrote ){ 273 if( wrote<0 && pFile->lastErrno!=ENOSPC ){ 274 /* lastErrno set by seekAndWrite */ 275+#ifdef LOG_DUMP 276+ sqlite3_log(SQLITE_IOERR_WRITE, 277+ "unixWrite, lastErrno set by seekAndWrite, fd[%d], offset[%lld], wrote[%d], amt[%d], lastErrno[%d]", 278+ pFile->h, offset, wrote, amt, pFile->lastErrno); 279+#endif /* LOG_DUMP */ 280 return SQLITE_IOERR_WRITE; 281 }else{ 282 storeLastErrno(pFile, 0); /* not a system error */ 283+#ifdef LOG_DUMP 284+ sqlite3_log(SQLITE_FULL, 285+ "unixWrite, not a system error, fd[%d], offset[%lld], wrote[%d], amt[%d], lastErrno[%d]", 286+ pFile->h, offset, wrote, amt, pFile->lastErrno); 287+#endif /* LOG_DUMP */ 288 return SQLITE_FULL; 289 } 290 } 291@@ -41951,7 +42078,14 @@ static int fcntlSizeHint(unixFile *pFile, i64 nByte){ 292 do{ 293 err = osFallocate(pFile->h, buf.st_size, nSize-buf.st_size); 294 }while( err==EINTR ); 295- if( err && err!=EINVAL ) return SQLITE_IOERR_WRITE; 296+ if( err && err!=EINVAL ) { 297+#ifdef LOG_DUMP 298+ sqlite3_log(SQLITE_IOERR_WRITE, 299+ "fcntlSizeHint-fallocate, fd[%d], bufSize[%lld], nSize[%lld] err[%d]", 300+ pFile->h, buf.st_size, nSize, err); 301+#endif /* LOG_DUMP */ 302+ return SQLITE_IOERR_WRITE; 303+ } 304 #else 305 /* If the OS does not have posix_fallocate(), fake it. Write a 306 ** single byte to the last byte in each block that falls entirely 307@@ -41970,7 +42104,14 @@ static int fcntlSizeHint(unixFile *pFile, i64 nByte){ 308 for(/*no-op*/; iWrite<nSize+nBlk-1; iWrite+=nBlk ){ 309 if( iWrite>=nSize ) iWrite = nSize - 1; 310 nWrite = seekAndWrite(pFile, iWrite, "", 1); 311- if( nWrite!=1 ) return SQLITE_IOERR_WRITE; 312+ if( nWrite!=1 ) { 313+#ifdef LOG_DUMP 314+ sqlite3_log(SQLITE_IOERR_WRITE, 315+ "fcntlSizeHint-seekAndWrite, fd[%d], nWrite[%d], nSize[%d], nBlk[%d], iWrite[%lld]", 316+ pFile->h, nWrite, nSize, nBlk, iWrite); 317+#endif /* LOG_DUMP */ 318+ return SQLITE_IOERR_WRITE; 319+ } 320 } 321 #endif 322 } 323@@ -42025,14 +42166,29 @@ static int unixFileControl(sqlite3_file *id, int op, void *pArg){ 324 #if defined(__linux__) && defined(SQLITE_ENABLE_BATCH_ATOMIC_WRITE) 325 case SQLITE_FCNTL_BEGIN_ATOMIC_WRITE: { 326 int rc = osIoctl(pFile->h, F2FS_IOC_START_ATOMIC_WRITE); 327+#ifdef LOG_DUMP 328+ if( rc ){ 329+ sqlite3_log(SQLITE_IOERR_BEGIN_ATOMIC, "unixFileControl-begin, fd[%d], op[%d]", pFile->h, op); 330+ } 331+#endif /* LOG_DUMP */ 332 return rc ? SQLITE_IOERR_BEGIN_ATOMIC : SQLITE_OK; 333 } 334 case SQLITE_FCNTL_COMMIT_ATOMIC_WRITE: { 335 int rc = osIoctl(pFile->h, F2FS_IOC_COMMIT_ATOMIC_WRITE); 336+#ifdef LOG_DUMP 337+ if( rc ){ 338+ sqlite3_log(SQLITE_IOERR_COMMIT_ATOMIC, "unixFileControl-commit, fd[%d], op[%d]", pFile->h, op); 339+ } 340+#endif /* LOG_DUMP */ 341 return rc ? SQLITE_IOERR_COMMIT_ATOMIC : SQLITE_OK; 342 } 343 case SQLITE_FCNTL_ROLLBACK_ATOMIC_WRITE: { 344 int rc = osIoctl(pFile->h, F2FS_IOC_ABORT_VOLATILE_WRITE); 345+#ifdef LOG_DUMP 346+ if( rc ){ 347+ sqlite3_log(SQLITE_IOERR_ROLLBACK_ATOMIC, "unixFileControl-rollback, fd[%d], op[%d]", pFile->h, op); 348+ } 349+#endif /* LOG_DUMP */ 350 return rc ? SQLITE_IOERR_ROLLBACK_ATOMIC : SQLITE_OK; 351 } 352 #endif /* __linux__ && SQLITE_ENABLE_BATCH_ATOMIC_WRITE */ 353@@ -42350,6 +42506,7 @@ struct unixShmNode { 354 int nRef; /* Number of unixShm objects pointing to this */ 355 unixShm *pFirst; /* All unixShm objects pointing to this */ 356 int aLock[SQLITE_SHM_NLOCK]; /* # shared locks on slot, -1==excl lock */ 357+ int aLockTid[SQLITE_SHM_NLOCK]; 358 #ifdef SQLITE_DEBUG 359 u8 exclMask; /* Mask of exclusive locks held */ 360 u8 sharedMask; /* Mask of shared locks held */ 361@@ -42592,6 +42749,8 @@ static int unixLockSharedMemory(unixFile *pDbFd, unixShmNode *pShmNode){ 362 rc = SQLITE_READONLY_CANTINIT; 363 }else{ 364 rc = unixShmSystemLock(pDbFd, F_WRLCK, UNIX_SHM_DMS, 1); 365+ MarkLockStatusByRc(rc, SHM_DMS_IDX, 1, EXCLUSIVE_LOCK, LOCK_BY_PROCESS); 366+ MARK_LAST_BUSY_LINE(rc); 367 /* The first connection to attach must truncate the -shm file. We 368 ** truncate to 3 bytes (an arbitrary small number, less than the 369 ** -shm header size) rather than 0 as a system debugging aid, to 370@@ -42603,11 +42762,15 @@ static int unixLockSharedMemory(unixFile *pDbFd, unixShmNode *pShmNode){ 371 } 372 }else if( lock.l_type==F_WRLCK ){ 373 rc = SQLITE_BUSY; 374+ MarkLockStatusByRc(rc, SHM_DMS_IDX, 1, SHARED_LOCK, LOCK_BY_PROCESS); 375+ MARK_LAST_BUSY_LINE(rc); 376 } 377 378 if( rc==SQLITE_OK ){ 379 assert( lock.l_type==F_UNLCK || lock.l_type==F_RDLCK ); 380 rc = unixShmSystemLock(pDbFd, F_RDLCK, UNIX_SHM_DMS, 1); 381+ MarkLockStatusByRc(rc, SHM_DMS_IDX, 1, SHARED_LOCK, LOCK_BY_PROCESS); 382+ MARK_LAST_BUSY_LINE(rc); 383 } 384 return rc; 385 } 386@@ -42720,6 +42883,9 @@ static int unixOpenSharedMemory(unixFile *pDbFd){ 387 (sStat.st_mode&0777)); 388 } 389 if( pShmNode->hShm<0 ){ 390+#ifdef LOG_DUMP 391+ int sysno = errno; 392+#endif 393 pShmNode->hShm = robust_open(zShm, O_RDONLY|O_NOFOLLOW, 394 (sStat.st_mode&0777)); 395 if( pShmNode->hShm<0 ){ 396@@ -42727,6 +42893,9 @@ static int unixOpenSharedMemory(unixFile *pDbFd){ 397 goto shm_open_err; 398 } 399 pShmNode->isReadonly = 1; 400+#ifdef LOG_DUMP 401+ sqlite3_log(SQLITE_WARNING_DUMP, "OpenSharedMemory node set to readonly sysno[%d]", sysno); 402+#endif 403 } 404 405 /* If this process is running as root, make sure that the SHM file 406@@ -42978,11 +43147,22 @@ static int unixShmLock( 407 int *aLock; 408 409 p = pDbFd->pShm; 410- if( p==0 ) return SQLITE_IOERR_SHMLOCK; 411+ if( p==0 ) { 412+#ifdef LOG_DUMP 413+ sqlite3_log(SQLITE_IOERR_SHMLOCK, "unixShmLock-pShm, fd[%d], ofst[%d], n[%d], flags[%d]", pDbFd->h, ofst, n, flags); 414+#endif 415+ return SQLITE_IOERR_SHMLOCK; 416+ } 417 pShmNode = p->pShmNode; 418- if( NEVER(pShmNode==0) ) return SQLITE_IOERR_SHMLOCK; 419+ if( NEVER(pShmNode==0) ) { 420+#ifdef LOG_DUMP 421+ sqlite3_log(SQLITE_IOERR_SHMLOCK, "unixShmLock-pShmNode, fd[%d], ofst[%d], n[%d], flags[%d]", pDbFd->h, ofst, n, flags); 422+#endif 423+ return SQLITE_IOERR_SHMLOCK; 424+ } 425 aLock = pShmNode->aLock; 426- 427+ int *aLockTid = pShmNode->aLockTid; 428+ u8 useProcessLock = LOCK_BY_THREAD; 429 assert( pShmNode==pDbFd->pInode->pShmNode ); 430 assert( pShmNode->pInode==pDbFd->pInode ); 431 assert( ofst>=0 && ofst+n<=SQLITE_SHM_NLOCK ); 432@@ -43037,15 +43217,17 @@ static int unixShmLock( 433 if( rc==SQLITE_OK ){ 434 memset(&aLock[ofst], 0, sizeof(int)*n); 435 } 436+ useProcessLock = LOCK_BY_PROCESS; 437 }else if( ALWAYS(p->sharedMask & (1<<ofst)) ){ 438 assert( n==1 && aLock[ofst]>1 ); 439 aLock[ofst]--; 440 } 441- 442+ MarkLockStatusByRc(rc, ofst, n, NO_LOCK, useProcessLock); 443 /* Undo the local locks */ 444 if( rc==SQLITE_OK ){ 445 p->exclMask &= ~mask; 446 p->sharedMask &= ~mask; 447+ TryClearTid(aLockTid, ofst, n); 448 } 449 } 450 }else if( flags & SQLITE_SHM_SHARED ){ 451@@ -43056,12 +43238,14 @@ static int unixShmLock( 452 rc = SQLITE_BUSY; 453 }else if( aLock[ofst]==0 ){ 454 rc = unixShmSystemLock(pDbFd, F_RDLCK, ofst+UNIX_SHM_BASE, n); 455+ useProcessLock = LOCK_BY_PROCESS; 456 } 457- 458+ MarkLockStatusByRc(rc, ofst, n, SHARED_LOCK, useProcessLock); 459 /* Get the local shared locks */ 460 if( rc==SQLITE_OK ){ 461 p->sharedMask |= mask; 462 aLock[ofst]++; 463+ TryRecordTid(aLockTid, ofst, n); 464 } 465 } 466 }else{ 467@@ -43080,14 +43264,17 @@ static int unixShmLock( 468 ** also update the in-memory values. */ 469 if( rc==SQLITE_OK ){ 470 rc = unixShmSystemLock(pDbFd, F_WRLCK, ofst+UNIX_SHM_BASE, n); 471+ useProcessLock = LOCK_BY_PROCESS; 472 if( rc==SQLITE_OK ){ 473 assert( (p->sharedMask & mask)==0 ); 474 p->exclMask |= mask; 475 for(ii=ofst; ii<ofst+n; ii++){ 476 aLock[ii] = -1; 477 } 478+ TryRecordTid(aLockTid, ofst, n); 479 } 480 } 481+ MarkLockStatusByRc(rc, ofst, n, EXCLUSIVE_LOCK, useProcessLock); 482 } 483 assert( assertLockingArrayOk(pShmNode) ); 484 sqlite3_mutex_leave(pShmNode->pShmMutex); 485@@ -44298,6 +44485,9 @@ static int unixOpen( 486 flags |= SQLITE_OPEN_READONLY; 487 openFlags |= O_RDONLY; 488 isReadonly = 1; 489+#ifdef LOG_DUMP 490+ sqlite3_log(SQLITE_WARNING, "Try open file readonly sysno %d", errno); 491+#endif 492 fd = robust_open(zName, openFlags, openMode); 493 } 494 } 495@@ -44357,6 +44547,9 @@ static int unixOpen( 496 if( fstatfs(fd, &fsInfo) == -1 ){ 497 storeLastErrno(p, errno); 498 robust_close(p, fd, __LINE__); 499+#ifdef LOG_DUMP 500+ sqlite3_log(SQLITE_IOERR_ACCESS, "unixOpen, fd[%d], flags[%d], errno[%d]", fd, errno, flags); 501+#endif /* LOG_DUMP */ 502 return SQLITE_IOERR_ACCESS; 503 } 504 if (0 == strncmp("msdos", fsInfo.f_fstypename, 5)) { 505@@ -44497,6 +44690,184 @@ static int unixAccess( 506 return SQLITE_OK; 507 } 508 509+#ifdef OS_FEATURE 510+/* 511+** If the last component of the pathname in z[0]..z[j-1] is something 512+** other than ".." then back it out and return true. If the last 513+** component is empty or if it is ".." then return false. 514+*/ 515+static int unixBackupDir(const char *z, int *pJ){ 516+ int j = *pJ; 517+ int i; 518+ if( j<=0 ) return 0; 519+ for(i=j-1; i>0 && z[i-1]!='/'; i--){} 520+ if( i==0 ) return 0; 521+ if( z[i]=='.' && i==j-2 && z[i+1]=='.' ) return 0; 522+ *pJ = i-1; 523+ return 1; 524+} 525+ 526+/* 527+** Convert a relative pathname into a full pathname. Also 528+** simplify the pathname as follows: 529+** 530+** Remove all instances of /./ 531+** Remove all isntances of /X/../ for any X 532+*/ 533+static int mkFullPathname( 534+ const char *zPath, /* Input path */ 535+ char *zOut, /* Output buffer */ 536+ int nOut /* Allocated size of buffer zOut */ 537+){ 538+ int nPath = sqlite3Strlen30(zPath); 539+ int iOff = 0; 540+ int i, j; 541+ if( zPath[0]!='/' ){ 542+ if( osGetcwd(zOut, nOut-2)==0 ){ 543+ return unixLogError(SQLITE_CANTOPEN_BKPT, "getcwd", zPath); 544+ } 545+ iOff = sqlite3Strlen30(zOut); 546+ zOut[iOff++] = '/'; 547+ } 548+ if( (iOff+nPath+1)>nOut ){ 549+ /* SQLite assumes that xFullPathname() nul-terminates the output buffer 550+ ** even if it returns an error. */ 551+ zOut[iOff] = '\0'; 552+ return SQLITE_CANTOPEN_BKPT; 553+ } 554+ sqlite3_snprintf(nOut-iOff, &zOut[iOff], "%s", zPath); 555+ 556+ /* Remove duplicate '/' characters. Except, two // at the beginning 557+ ** of a pathname is allowed since this is important on windows. */ 558+ for(i=j=1; zOut[i]; i++){ 559+ zOut[j++] = zOut[i]; 560+ while( zOut[i]=='/' && zOut[i+1]=='/' ) i++; 561+ } 562+ zOut[j] = 0; 563+ 564+ assert( zOut[0]=='/' ); 565+ for(i=j=0; zOut[i]; i++){ 566+ if( zOut[i]=='/' ){ 567+ /* Skip over internal "/." directory components */ 568+ if( zOut[i+1]=='.' && zOut[i+2]=='/' ){ 569+ i += 1; 570+ continue; 571+ } 572+ 573+ /* If this is a "/.." directory component then back out the 574+ ** previous term of the directory if it is something other than "..". 575+ */ 576+ if( zOut[i+1]=='.' 577+ && zOut[i+2]=='.' 578+ && zOut[i+3]=='/' 579+ && unixBackupDir(zOut, &j) 580+ ){ 581+ i += 2; 582+ continue; 583+ } 584+ } 585+ if( ALWAYS(j>=0) ) zOut[j] = zOut[i]; 586+ j++; 587+ } 588+ if( NEVER(j==0) ) zOut[j++] = '/'; 589+ zOut[j] = 0; 590+ return SQLITE_OK; 591+} 592+ 593+/* 594+** Turn a relative pathname into a full pathname. The relative path 595+** is stored as a nul-terminated string in the buffer pointed to by 596+** zPath. 597+** 598+** zOut points to a buffer of at least sqlite3_vfs.mxPathname bytes 599+** (in this case, MAX_PATHNAME bytes). The full-path is written to 600+** this buffer before returning. 601+*/ 602+static int unixFullPathname( 603+ sqlite3_vfs *pVfs, /* Pointer to vfs object */ 604+ const char *zPath, /* Possibly relative input path */ 605+ int nOut, /* Size of output buffer in bytes */ 606+ char *zOut /* Output buffer */ 607+){ 608+#if !defined(HAVE_READLINK) || !defined(HAVE_LSTAT) 609+ return mkFullPathname(zPath, zOut, nOut); 610+#else 611+ int rc = SQLITE_OK; 612+ int nByte; 613+ int nLink = 0; /* Number of symbolic links followed so far */ 614+ const char *zIn = zPath; /* Input path for each iteration of loop */ 615+ char *zDel = 0; 616+ 617+ assert( pVfs->mxPathname==MAX_PATHNAME ); 618+ UNUSED_PARAMETER(pVfs); 619+ 620+ /* It's odd to simulate an io-error here, but really this is just 621+ ** using the io-error infrastructure to test that SQLite handles this 622+ ** function failing. This function could fail if, for example, the 623+ ** current working directory has been unlinked. 624+ */ 625+ SimulateIOError( return SQLITE_ERROR ); 626+ 627+ do { 628+ 629+ /* Call stat() on path zIn. Set bLink to true if the path is a symbolic 630+ ** link, or false otherwise. */ 631+ int bLink = 0; 632+ struct stat buf; 633+ if( osLstat(zIn, &buf)!=0 ){ 634+ if( errno!=ENOENT ){ 635+ rc = unixLogError(SQLITE_CANTOPEN_BKPT, "lstat", zIn); 636+ } 637+ }else{ 638+ bLink = S_ISLNK(buf.st_mode); 639+ } 640+ 641+ if( bLink ){ 642+ nLink++; 643+ if( zDel==0 ){ 644+ zDel = sqlite3_malloc(nOut); 645+ if( zDel==0 ) rc = SQLITE_NOMEM_BKPT; 646+ }else if( nLink>=SQLITE_MAX_SYMLINK ){ 647+ rc = SQLITE_CANTOPEN_BKPT; 648+ } 649+ 650+ if( rc==SQLITE_OK ){ 651+ nByte = osReadlink(zIn, zDel, nOut-1); 652+ if( nByte<0 ){ 653+ rc = unixLogError(SQLITE_CANTOPEN_BKPT, "readlink", zIn); 654+ }else{ 655+ if( zDel[0]!='/' ){ 656+ int n; 657+ for(n = sqlite3Strlen30(zIn); n>0 && zIn[n-1]!='/'; n--); 658+ if( nByte+n+1>nOut ){ 659+ rc = SQLITE_CANTOPEN_BKPT; 660+ }else{ 661+ memmove(&zDel[n], zDel, nByte+1); 662+ memcpy(zDel, zIn, n); 663+ nByte += n; 664+ } 665+ } 666+ zDel[nByte] = '\0'; 667+ } 668+ } 669+ 670+ zIn = zDel; 671+ } 672+ 673+ assert( rc!=SQLITE_OK || zIn!=zOut || zIn[0]=='/' ); 674+ if( rc==SQLITE_OK && zIn!=zOut ){ 675+ rc = mkFullPathname(zIn, zOut, nOut); 676+ } 677+ if( bLink==0 ) break; 678+ zIn = zOut; 679+ }while( rc==SQLITE_OK ); 680+ 681+ sqlite3_free(zDel); 682+ if( rc==SQLITE_OK && nLink ) rc = SQLITE_OK_SYMLINK; 683+ return rc; 684+#endif /* HAVE_READLINK && HAVE_LSTAT */ 685+} 686+#else 687 /* 688 ** A pathname under construction 689 */ 690@@ -44626,6 +44997,7 @@ static int unixFullPathname( 691 if( path.nSymlink ) return SQLITE_OK_SYMLINK; 692 return SQLITE_OK; 693 } 694+#endif 695 696 #ifndef SQLITE_OMIT_LOAD_EXTENSION 697 /* 698@@ -45037,6 +45409,9 @@ static int proxyGetLockPath(const char *dbPath, char *lPath, size_t maxLen){ 699 if( !confstr(_CS_DARWIN_USER_TEMP_DIR, lPath, maxLen) ){ 700 OSTRACE(("GETLOCKPATH failed %s errno=%d pid=%d\n", 701 lPath, errno, osGetpid(0))); 702+#ifdef LOG_DUMP 703+ sqlite3_log(SQLITE_IOERR_LOCK, "proxyGetLockPath len[%d], dbLen[%d], i[%d]", len, dbLen, i); 704+#endif /* LOG_DUMP */ 705 return SQLITE_IOERR_LOCK; 706 } 707 len = strlcat(lPath, "sqliteplocks", maxLen); 708@@ -45155,6 +45530,9 @@ static int proxyCreateUnixFile( 709 case EACCES: 710 return SQLITE_PERM; 711 case EIO: 712+#ifdef LOG_DUMP 713+ sqlite3_log(SQLITE_IOERR_LOCK, "proxyCreateUnixFile-EIO, fd[%d]", fd); 714+#endif /* LOG_DUMP */ 715 return SQLITE_IOERR_LOCK; /* even though it is the conch */ 716 default: 717 return SQLITE_CANTOPEN_BKPT; 718@@ -45323,6 +45701,9 @@ static int proxyConchLock(unixFile *pFile, uuid_t myHostID, int lockType){ 719 struct stat buf; 720 if( osFstat(conchFile->h, &buf) ){ 721 storeLastErrno(pFile, errno); 722+#ifdef LOG_DUMP 723+ sqlite3_log(SQLITE_IOERR_LOCK, "proxyConchLock pFile fd[%d], conchFile fd[%d], lastErrno[%d]", pFile->h, conchFile->h, errno); 724+#endif /* LOG_DUMP */ 725 return SQLITE_IOERR_LOCK; 726 } 727 728@@ -45343,6 +45724,9 @@ static int proxyConchLock(unixFile *pFile, uuid_t myHostID, int lockType){ 729 int len = osPread(conchFile->h, tBuf, PROXY_MAXCONCHLEN, 0); 730 if( len<0 ){ 731 storeLastErrno(pFile, errno); 732+#ifdef LOG_DUMP 733+ sqlite3_log(SQLITE_IOERR_LOCK, "proxyConchLock tries 2, pFile fd[%d], conchFile fd[%d], lastErrno[%d]", pFile->h, conchFile->h, errno); 734+#endif /* LOG_DUMP */ 735 return SQLITE_IOERR_LOCK; 736 } 737 if( len>PROXY_PATHINDEX && tBuf[0]==(char)PROXY_CONCHVERSION){ 738@@ -45417,6 +45801,9 @@ static int proxyTakeConch(unixFile *pFile){ 739 if( readLen<0 ){ 740 /* I/O error: lastErrno set by seekAndRead */ 741 storeLastErrno(pFile, conchFile->lastErrno); 742+#ifdef LOG_DUMP 743+ sqlite3_log(SQLITE_IOERR_READ, "proxyTakeConch pFile fd[%d], conchFile fd[%d], lastErrno[%d]", pFile->h, conchFile->h, conchFile->lastErrno); 744+#endif /* LOG_DUMP */ 745 rc = SQLITE_IOERR_READ; 746 goto end_takeconch; 747 }else if( readLen<=(PROXY_HEADERLEN+PROXY_HOSTIDLEN) || 748@@ -60983,6 +61370,7 @@ static int syncJournal(Pager *pPager, int newHdr){ 749 assert( !pagerUseWal(pPager) ); 750 751 rc = sqlite3PagerExclusiveLock(pPager); 752+ MARK_LAST_BUSY_LINE(rc); 753 if( rc!=SQLITE_OK ) return rc; 754 755 if( !pPager->noSync ){ 756@@ -61682,6 +62070,10 @@ SQLITE_PRIVATE int sqlite3PagerOpen( 757 if( (iDc & SQLITE_IOCAP_IMMUTABLE)!=0 758 || sqlite3_uri_boolean(pPager->zFilename, "immutable", 0) ){ 759 vfsFlags |= SQLITE_OPEN_READONLY; 760+#ifdef LOG_DUMP 761+ sqlite3_log(SQLITE_WARNING_DUMP, "Vfsflag set to readonly, readOnly[%d], vfsFlags[%d], sysno[%d]", 762+ readOnly, vfsFlags, errno); 763+#endif 764 goto act_like_temp_file; 765 } 766 } 767@@ -61875,6 +62267,7 @@ static int hasHotJournal(Pager *pPager, int *pExists){ 768 sqlite3OsDelete(pVfs, pPager->zJournal, 0); 769 if( !pPager->exclusiveMode ) pagerUnlockDb(pPager, SHARED_LOCK); 770 } 771+ MARK_LAST_BUSY_LINE(rc); 772 sqlite3EndBenignMalloc(); 773 }else{ 774 /* The journal file exists and no other connection has a reserved 775@@ -61964,6 +62357,7 @@ SQLITE_PRIVATE int sqlite3PagerSharedLock(Pager *pPager){ 776 assert( pPager->tempFile==0 || pPager->eLock==EXCLUSIVE_LOCK ); 777 778 rc = pager_wait_on_lock(pPager, SHARED_LOCK); 779+ MARK_LAST_BUSY_LINE(rc); 780 if( rc!=SQLITE_OK ){ 781 assert( pPager->eLock==NO_LOCK || pPager->eLock==UNKNOWN_LOCK ); 782 goto failed; 783@@ -62000,6 +62394,7 @@ SQLITE_PRIVATE int sqlite3PagerSharedLock(Pager *pPager){ 784 ** downgraded to SHARED_LOCK before this function returns. 785 */ 786 rc = pagerLockDb(pPager, EXCLUSIVE_LOCK); 787+ MARK_LAST_BUSY_LINE(rc); 788 if( rc!=SQLITE_OK ){ 789 goto failed; 790 } 791@@ -62632,6 +63027,7 @@ SQLITE_PRIVATE int sqlite3PagerBegin(Pager *pPager, int exFlag, int subjInMemory 792 */ 793 if( pPager->exclusiveMode && sqlite3WalExclusiveMode(pPager->pWal, -1) ){ 794 rc = pagerLockDb(pPager, EXCLUSIVE_LOCK); 795+ MARK_LAST_BUSY_LINE(rc); 796 if( rc!=SQLITE_OK ){ 797 return rc; 798 } 799@@ -62644,6 +63040,7 @@ SQLITE_PRIVATE int sqlite3PagerBegin(Pager *pPager, int exFlag, int subjInMemory 800 ** holds the write-lock. If possible, the upper layer will call it. 801 */ 802 rc = sqlite3WalBeginWriteTransaction(pPager->pWal); 803+ MARK_LAST_BUSY_LINE(rc); 804 }else{ 805 /* Obtain a RESERVED lock on the database file. If the exFlag parameter 806 ** is true, then immediately upgrade this to an EXCLUSIVE lock. The 807@@ -62651,8 +63048,10 @@ SQLITE_PRIVATE int sqlite3PagerBegin(Pager *pPager, int exFlag, int subjInMemory 808 ** lock, but not when obtaining the RESERVED lock. 809 */ 810 rc = pagerLockDb(pPager, RESERVED_LOCK); 811+ MARK_LAST_BUSY_LINE(rc); 812 if( rc==SQLITE_OK && exFlag ){ 813 rc = pager_wait_on_lock(pPager, EXCLUSIVE_LOCK); 814+ MARK_LAST_BUSY_LINE(rc); 815 } 816 } 817 818@@ -64164,6 +64563,7 @@ SQLITE_PRIVATE int sqlite3PagerSetJournalMode(Pager *pPager, int eMode){ 819 if( pPager->eState==PAGER_READER ){ 820 assert( rc==SQLITE_OK ); 821 rc = pagerLockDb(pPager, RESERVED_LOCK); 822+ MARK_LAST_BUSY_LINE(rc); 823 } 824 if( rc==SQLITE_OK ){ 825 sqlite3OsDelete(pPager->pVfs, pPager->zJournal, 0); 826@@ -64330,6 +64730,7 @@ static int pagerOpenWal(Pager *pPager){ 827 */ 828 if( pPager->exclusiveMode ){ 829 rc = pagerExclusiveLock(pPager); 830+ MARK_LAST_BUSY_LINE(rc); 831 } 832 833 /* Open the connection to the log file. If this operation fails, 834@@ -64413,6 +64814,7 @@ SQLITE_PRIVATE int sqlite3PagerCloseWal(Pager *pPager, sqlite3 *db){ 835 if( !pPager->pWal ){ 836 int logexists = 0; 837 rc = pagerLockDb(pPager, SHARED_LOCK); 838+ MARK_LAST_BUSY_LINE(rc); 839 if( rc==SQLITE_OK ){ 840 rc = sqlite3OsAccess( 841 pPager->pVfs, pPager->zWal, SQLITE_ACCESS_EXISTS, &logexists 842@@ -64428,6 +64830,7 @@ SQLITE_PRIVATE int sqlite3PagerCloseWal(Pager *pPager, sqlite3 *db){ 843 */ 844 if( rc==SQLITE_OK && pPager->pWal ){ 845 rc = pagerExclusiveLock(pPager); 846+ MARK_LAST_BUSY_LINE(rc); 847 if( rc==SQLITE_OK ){ 848 rc = sqlite3WalClose(pPager->pWal, db, pPager->walSyncFlags, 849 pPager->pageSize, (u8*)pPager->pTmpSpace); 850@@ -65352,6 +65755,9 @@ static SQLITE_NOINLINE int walIndexPageRealloc( 851 if( iPage>0 && sqlite3FaultSim(600) ) rc = SQLITE_NOMEM; 852 }else if( (rc&0xff)==SQLITE_READONLY ){ 853 pWal->readOnly |= WAL_SHM_RDONLY; 854+#ifdef LOG_DUMP 855+ sqlite3_log(rc, "PagerRealloc wal set to readonly, sysno[%d]", errno); 856+#endif 857 if( rc==SQLITE_READONLY ){ 858 rc = SQLITE_OK; 859 } 860@@ -65962,6 +66368,7 @@ static int walIndexRecover(Wal *pWal){ 861 iLock = WAL_ALL_BUT_WRITE + pWal->ckptLock; 862 rc = walLockExclusive(pWal, iLock, WAL_READ_LOCK(0)-iLock); 863 if( rc ){ 864+ MARK_LAST_BUSY_LINE(rc); 865 return rc; 866 } 867 868@@ -66795,6 +67202,7 @@ static int walCheckpoint( 869 if( mxSafeFrame>y ){ 870 assert( y<=pWal->hdr.mxFrame ); 871 rc = walBusyLock(pWal, xBusy, pBusyArg, WAL_READ_LOCK(i), 1); 872+ MARK_LAST_BUSY_LINE(rc); 873 if( rc==SQLITE_OK ){ 874 u32 iMark = (i==1 ? mxSafeFrame : READMARK_NOT_USED); 875 AtomicStore(pInfo->aReadMark+i, iMark); SEH_INJECT_FAULT; 876@@ -66885,6 +67293,8 @@ static int walCheckpoint( 877 878 /* Release the reader lock held while backfilling */ 879 walUnlockExclusive(pWal, WAL_READ_LOCK(0), 1); 880+ } else { 881+ MARK_LAST_BUSY_LINE(rc); 882 } 883 884 if( rc==SQLITE_BUSY ){ 885@@ -66904,11 +67314,13 @@ static int walCheckpoint( 886 SEH_INJECT_FAULT; 887 if( pInfo->nBackfill<pWal->hdr.mxFrame ){ 888 rc = SQLITE_BUSY; 889+ MARK_LAST_BUSY_LINE(rc); 890 }else if( eMode>=SQLITE_CHECKPOINT_RESTART ){ 891 u32 salt1; 892 sqlite3_randomness(4, &salt1); 893 assert( pInfo->nBackfill==pWal->hdr.mxFrame ); 894 rc = walBusyLock(pWal, xBusy, pBusyArg, WAL_READ_LOCK(1), WAL_NREADER-1); 895+ MARK_LAST_BUSY_LINE(rc); 896 if( rc==SQLITE_OK ){ 897 if( eMode==SQLITE_CHECKPOINT_TRUNCATE ){ 898 /* IMPLEMENTATION-OF: R-44699-57140 This mode works the same way as 899@@ -67096,6 +67508,8 @@ SQLITE_PRIVATE int sqlite3WalClose( 900 walLimitSize(pWal, 0); 901 } 902 } 903+ } else { 904+ MARK_LAST_BUSY_LINE(rc); 905 } 906 907 walIndexClose(pWal, isDelete); 908@@ -67250,6 +67664,7 @@ static int walIndexReadHdr(Wal *pWal, int *pChanged){ 909 walUnlockShared(pWal, WAL_WRITE_LOCK); 910 rc = SQLITE_READONLY_RECOVERY; 911 } 912+ MARK_LAST_BUSY_LINE(rc); 913 }else{ 914 int bWriteLock = pWal->writeLock; 915 if( bWriteLock || SQLITE_OK==(rc = walLockWriter(pWal)) ){ 916@@ -67270,6 +67685,7 @@ static int walIndexReadHdr(Wal *pWal, int *pChanged){ 917 walUnlockExclusive(pWal, WAL_WRITE_LOCK, 1); 918 } 919 } 920+ MARK_LAST_BUSY_LINE(rc); 921 } 922 } 923 924@@ -67289,6 +67705,7 @@ static int walIndexReadHdr(Wal *pWal, int *pChanged){ 925 ** writer truncated the WAL out from under it. If that happens, it 926 ** indicates that a writer has fixed the SHM file for us, so retry */ 927 if( rc==SQLITE_IOERR_SHORT_READ ) rc = WAL_RETRY; 928+ MARK_LAST_BUSY_LINE(rc); 929 } 930 pWal->exclusiveMode = WAL_NORMAL_MODE; 931 } 932@@ -67520,6 +67937,7 @@ static int walBeginShmUnreliable(Wal *pWal, int *pChanged){ 933 ** so it takes care to hold an exclusive lock on the corresponding 934 ** WAL_READ_LOCK() while changing values. 935 */ 936+static void DumpLocksByWal(Wal *pWal); 937 static int walTryBeginRead(Wal *pWal, int *pChanged, int useWal, int cnt){ 938 volatile WalCkptInfo *pInfo; /* Checkpoint information in wal-index */ 939 u32 mxReadMark; /* Largest aReadMark[] value */ 940@@ -67557,6 +67975,9 @@ static int walTryBeginRead(Wal *pWal, int *pChanged, int useWal, int cnt){ 941 return SQLITE_PROTOCOL; 942 } 943 if( cnt>=10 ) nDelay = (cnt-9)*(cnt-9)*39; 944+#if SQLITE_OS_UNIX 945+ if( cnt>=15 ) DumpLocksByWal(pWal); 946+#endif /* SQLITE_OS_UNIX */ 947 sqlite3OsSleep(pWal->pVfs, nDelay); 948 } 949 950@@ -67583,11 +68004,14 @@ static int walTryBeginRead(Wal *pWal, int *pChanged, int useWal, int cnt){ 951 ** must be zeroed before the requested page is returned. 952 */ 953 rc = WAL_RETRY; 954+ MARK_LAST_BUSY_LINE(SQLITE_BUSY); 955 }else if( SQLITE_OK==(rc = walLockShared(pWal, WAL_RECOVER_LOCK)) ){ 956 walUnlockShared(pWal, WAL_RECOVER_LOCK); 957 rc = WAL_RETRY; 958+ MARK_LAST_BUSY_LINE(SQLITE_BUSY); 959 }else if( rc==SQLITE_BUSY ){ 960 rc = SQLITE_BUSY_RECOVERY; 961+ MARK_LAST_BUSY_LINE(SQLITE_BUSY); 962 } 963 } 964 if( rc!=SQLITE_OK ){ 965@@ -67611,6 +68035,7 @@ static int walTryBeginRead(Wal *pWal, int *pChanged, int useWal, int cnt){ 966 ** and can be safely ignored. 967 */ 968 rc = walLockShared(pWal, WAL_READ_LOCK(0)); 969+ MARK_LAST_BUSY_LINE(SQLITE_BUSY); 970 walShmBarrier(pWal); 971 if( rc==SQLITE_OK ){ 972 if( memcmp((void *)walIndexHdr(pWal), &pWal->hdr, sizeof(WalIndexHdr)) ){ 973@@ -67628,6 +68053,7 @@ static int walTryBeginRead(Wal *pWal, int *pChanged, int useWal, int cnt){ 974 ** it finished. Leaving a corrupt image in the database file. 975 */ 976 walUnlockShared(pWal, WAL_READ_LOCK(0)); 977+ MARK_LAST_BUSY_LINE(SQLITE_BUSY); 978 return WAL_RETRY; 979 } 980 pWal->readLock = 0; 981@@ -67672,6 +68098,7 @@ static int walTryBeginRead(Wal *pWal, int *pChanged, int useWal, int cnt){ 982 }else if( rc!=SQLITE_BUSY ){ 983 return rc; 984 } 985+ MARK_LAST_BUSY_LINE(rc); 986 } 987 } 988 if( mxI==0 ){ 989@@ -67681,6 +68108,7 @@ static int walTryBeginRead(Wal *pWal, int *pChanged, int useWal, int cnt){ 990 991 rc = walLockShared(pWal, WAL_READ_LOCK(mxI)); 992 if( rc ){ 993+ MARK_LAST_BUSY_LINE(rc); 994 return rc==SQLITE_BUSY ? WAL_RETRY : rc; 995 } 996 /* Now that the read-lock has been obtained, check that neither the 997@@ -67723,6 +68151,7 @@ static int walTryBeginRead(Wal *pWal, int *pChanged, int useWal, int cnt){ 998 || memcmp((void *)walIndexHdr(pWal), &pWal->hdr, sizeof(WalIndexHdr)) 999 ){ 1000 walUnlockShared(pWal, WAL_READ_LOCK(mxI)); 1001+ MARK_LAST_BUSY_LINE(rc); 1002 return WAL_RETRY; 1003 }else{ 1004 assert( mxReadMark<=pWal->hdr.mxFrame ); 1005@@ -67860,6 +68289,7 @@ static int walBeginReadTransaction(Wal *pWal, int *pChanged){ 1006 (void)walEnableBlocking(pWal); 1007 rc = walLockShared(pWal, WAL_CKPT_LOCK); 1008 walDisableBlocking(pWal); 1009+ MARK_LAST_BUSY_LINE(rc); 1010 1011 if( rc!=SQLITE_OK ){ 1012 return rc; 1013@@ -68722,6 +69152,9 @@ static int walFrames( 1014 return rc; 1015 } 1016 1017+#ifdef LOG_DUMP 1018+static sqlite3_int64 g_lastCkptTime = 0; 1019+#endif /* LOG_DUMP */ 1020 /* 1021 ** Write a set of frames to the log. The caller must hold the write-lock 1022 ** on the log file (obtained using sqlite3WalBeginWriteTransaction()). 1023@@ -68755,6 +69188,7 @@ SQLITE_PRIVATE int sqlite3WalFrames( 1024 ** If parameter xBusy is not NULL, it is a pointer to a busy-handler 1025 ** callback. In this case this function runs a blocking checkpoint. 1026 */ 1027+static void walLogCheckpointInfo(Wal *pWal, sqlite3 *db, sqlite3_int64 startTime); 1028 SQLITE_PRIVATE int sqlite3WalCheckpoint( 1029 Wal *pWal, /* Wal connection */ 1030 sqlite3 *db, /* Check this handle's interrupt flag */ 1031@@ -68796,6 +69230,7 @@ SQLITE_PRIVATE int sqlite3WalCheckpoint( 1032 ** it will not be invoked in this case. 1033 */ 1034 rc = walLockExclusive(pWal, WAL_CKPT_LOCK, 1); 1035+ MARK_LAST_BUSY_LINE(rc); 1036 testcase( rc==SQLITE_BUSY ); 1037 testcase( rc!=SQLITE_OK && xBusy2!=0 ); 1038 if( rc==SQLITE_OK ){ 1039@@ -68812,6 +69247,7 @@ SQLITE_PRIVATE int sqlite3WalCheckpoint( 1040 */ 1041 if( eMode!=SQLITE_CHECKPOINT_PASSIVE ){ 1042 rc = walBusyLock(pWal, xBusy2, pBusyArg, WAL_WRITE_LOCK, 1); 1043+ MARK_LAST_BUSY_LINE(rc); 1044 if( rc==SQLITE_OK ){ 1045 pWal->writeLock = 1; 1046 }else if( rc==SQLITE_BUSY ){ 1047@@ -68839,7 +69275,12 @@ SQLITE_PRIVATE int sqlite3WalCheckpoint( 1048 if( pWal->hdr.mxFrame && walPagesize(pWal)!=nBuf ){ 1049 rc = SQLITE_CORRUPT_BKPT; 1050 }else{ 1051- rc = walCheckpoint(pWal, db, eMode2, xBusy2, pBusyArg, sync_flags,zBuf); 1052+ sqlite3_int64 startTime; 1053+ sqlite3OsCurrentTimeInt64(db->pVfs, &startTime); 1054+ rc = walCheckpoint(pWal, db, eMode2, xBusy2, pBusyArg, sync_flags, zBuf); 1055+ if (rc == SQLITE_OK){ 1056+ walLogCheckpointInfo(pWal, db, startTime); 1057+ } 1058 } 1059 1060 /* If no error occurred, set the output variables. */ 1061@@ -68871,6 +69312,12 @@ SQLITE_PRIVATE int sqlite3WalCheckpoint( 1062 walUnlockExclusive(pWal, WAL_CKPT_LOCK, 1); 1063 pWal->ckptLock = 0; 1064 } 1065+#ifdef LOG_DUMP 1066+ if( rc ){ 1067+ sqlite3_log(SQLITE_NOTICE, "ckpt rc[%d]", rc); 1068+ } 1069+ sqlite3OsCurrentTimeInt64(db->pVfs, &g_lastCkptTime); 1070+#endif /* LOG_DUMP */ 1071 WALTRACE(("WAL%p: checkpoint %s\n", pWal, rc ? "failed" : "ok")); 1072 #ifdef SQLITE_ENABLE_SETLK_TIMEOUT 1073 if( rc==SQLITE_BUSY_TIMEOUT ) rc = SQLITE_BUSY; 1074@@ -72155,6 +72602,13 @@ static int decodeFlags(MemPage *pPage, int flagByte){ 1075 pPage->intKeyLeaf = 0; 1076 pPage->xCellSize = cellSizePtr; 1077 pPage->xParseCell = btreeParseCellPtrIndex; 1078+#ifdef LOG_DUMP 1079+ sqlite3_log(SQLITE_CORRUPT, 1080+ "database corruption at page[%u], flagByte[%x], isInit[%u], intKey[%u], intKeyLeaf[%u], leaf[%u], " 1081+ "childPtrSize[%u], cellOffset[%u], nCell[%u], hdrOffset[%u], minLocal[%u], maxLocal[%u], last ckpt time[%lld]", 1082+ pPage->pgno, flagByte, pPage->isInit, pPage->intKey, pPage->intKeyLeaf, pPage->leaf, 1083+ pPage->childPtrSize, pPage->cellOffset, pPage->nCell, pPage->hdrOffset, pPage->minLocal, pPage->maxLocal, g_lastCkptTime); 1084+#endif /* LOG_DUMP */ 1085 return SQLITE_CORRUPT_PAGE(pPage); 1086 } 1087 } 1088@@ -72571,6 +73025,7 @@ static void pageReinit(DbPage *pData){ 1089 } 1090 } 1091 1092+static void DumpLocksByPager(Pager *pPager); 1093 /* 1094 ** Invoke the busy handler for a btree. 1095 */ 1096@@ -72578,7 +73033,13 @@ static int btreeInvokeBusyHandler(void *pArg){ 1097 BtShared *pBt = (BtShared*)pArg; 1098 assert( pBt->db ); 1099 assert( sqlite3_mutex_held(pBt->db->mutex) ); 1100- return sqlite3InvokeBusyHandler(&pBt->db->busyHandler); 1101+ int rc = sqlite3InvokeBusyHandler(&pBt->db->busyHandler); 1102+#if SQLITE_OS_UNIX 1103+ if (rc == 0) { 1104+ DumpLocksByPager(pBt->pPager); 1105+ } 1106+#endif /* SQLITE_OS_UNIX */ 1107+ return rc; 1108 } 1109 1110 /* 1111@@ -73009,7 +73470,7 @@ SQLITE_PRIVATE int sqlite3BtreeClose(Btree *p){ 1112 } 1113 } 1114 #endif 1115- 1116+ ResetLockStatus(); 1117 /* Rollback any active transaction and free the handle structure. 1118 ** The call to sqlite3BtreeRollback() drops any table-locks held by 1119 ** this handle. 1120@@ -73393,6 +73854,9 @@ static int lockBtree(BtShared *pBt){ 1121 #else 1122 if( page1[18]>2 ){ 1123 pBt->btsFlags |= BTS_READ_ONLY; 1124+#ifdef LOG_DUMP 1125+ sqlite3_log(SQLITE_WARNING_DUMP, "Mark bts readonly %u", get4byte(&page1[18])); 1126+#endif 1127 } 1128 if( page1[19]>2 ){ 1129 goto page1_init_failed; 1130@@ -73674,7 +74138,7 @@ static SQLITE_NOINLINE int btreeBeginTrans( 1131 1132 sqlite3BtreeEnter(p); 1133 btreeIntegrity(p); 1134- 1135+ ResetLockStatus(); 1136 /* If the btree is already in a write-transaction, or it 1137 ** is already in a read-transaction and a read-transaction 1138 ** is requested, this is a no-op. 1139@@ -81274,8 +81738,10 @@ SQLITE_PRIVATE int sqlite3BtreeCheckpoint(Btree *p, int eMode, int *pnLog, int * 1140 if( p ){ 1141 BtShared *pBt = p->pBt; 1142 sqlite3BtreeEnter(p); 1143+ ResetLockStatus(); 1144 if( pBt->inTransaction!=TRANS_NONE ){ 1145 rc = SQLITE_LOCKED; 1146+ MARK_LAST_BUSY_LINE(rc); 1147 }else{ 1148 rc = sqlite3PagerCheckpoint(pBt->pPager, p->db, eMode, pnLog, pnCkpt); 1149 } 1150@@ -87285,6 +87751,7 @@ static int vdbeCommit(sqlite3 *db, Vdbe *p){ 1151 nTrans++; 1152 } 1153 rc = sqlite3PagerExclusiveLock(pPager); 1154+ MARK_LAST_BUSY_LINE(rc); 1155 sqlite3BtreeLeave(pBt); 1156 } 1157 } 1158@@ -254452,6 +254919,256 @@ export_finish: 1159 /************** End file hw_codec.c *****************************************/ 1160 #endif 1161 1162+#if SQLITE_OS_UNIX 1163+#include <unistd.h> 1164+#include <sys/syscall.h> 1165+static inline int OsGetTid(void) 1166+{ 1167+#if defined(__linux__) 1168+ return (int)syscall(__NR_gettid); 1169+#elif defined(__APPLE__) 1170+ return (int)syscall(SYS_thread_selfid); 1171+#else 1172+ return 0; 1173+#endif 1174+} 1175+ 1176+static void ResetLockStatus(void) 1177+{ 1178+ (void)memset(&g_lockStatus, 0, sizeof(g_lockStatus)); 1179+ g_lockStatus.curTid = OsGetTid(); 1180+} 1181+/* 1182+** Record lock info, correspond wal aLock buf, 1 aLock: 1 1183+*/ 1184+static inline void TryRecordTid(int *tidBuf, int ofs, int lockLen) 1185+{ 1186+ int lockOfs = ofs + lockLen; 1187+ for (int i = ofs; i < lockOfs; i++) { 1188+ if (tidBuf[i] == 0) { 1189+ tidBuf[i] = g_lockStatus.curTid; 1190+ } 1191+ } 1192+} 1193+/* 1194+** Clear locks info. 1195+*/ 1196+static inline void TryClearTid(int *tidBuf, int ofs, int lockLen) 1197+{ 1198+ int lockOfs = ofs + lockLen; 1199+ for (int i = ofs; i < lockOfs; i++) { 1200+ if (tidBuf[i] == g_lockStatus.curTid) { 1201+ tidBuf[i] = 0; 1202+ } 1203+ } 1204+} 1205+ 1206+static inline void MarkLockBusy(u32 lockIdx, u32 lockLen, u8 lockType, u8 lockByProcess) 1207+{ 1208+ g_lockStatus.busyLockIdx = lockIdx; 1209+ g_lockStatus.busyLockType = lockType; 1210+ g_lockStatus.lockByProcess = lockByProcess; 1211+ g_lockStatus.lockLen = lockLen; 1212+} 1213+ 1214+static void MarkLockStatus(u32 lockIdx, u32 lockLen, u8 lockType) 1215+{ 1216+ if (lockLen == 0 || (lockIdx + lockLen) > MAX_LOCK_NUM) { 1217+ sqlite3_log(SQLITE_ERROR, "Unexpect lock index %u lockLen %d!", lockIdx, lockLen); 1218+ return; 1219+ } 1220+ // only busy error code need record 1221+ if (g_lockStatus.lockLen != 0 && lockIdx == g_lockStatus.busyLockIdx) { 1222+ g_lockStatus.busyLockIdx = 0; 1223+ g_lockStatus.busyLockType = NO_LOCK; 1224+ g_lockStatus.lockLen = 0; 1225+ } 1226+ if (lockLen == 1) { 1227+ g_lockStatus.lockStatus[lockIdx] = lockType; 1228+ } else { 1229+ size_t len = sizeof(u8) * lockLen; 1230+ (void)memset(&g_lockStatus.lockStatus[lockIdx], lockType, len); 1231+ } 1232+} 1233+ 1234+static inline void MarkLockStatusByRc(int rc, u32 lockIdx, u32 lockLen, u8 lockType, u8 lockByProcess) 1235+{ 1236+ if (rc == SQLITE_OK) { 1237+ MarkLockStatus(lockIdx, lockLen, lockType); 1238+ } else if (rc == SQLITE_BUSY) { 1239+ MarkLockBusy(lockIdx, lockLen, lockType, lockByProcess); 1240+ } 1241+} 1242+ 1243+static inline const char *IdxToLockName(u32 idx) 1244+{ 1245+ const char *lockName[MAX_LOCK_NUM] = {"write", "ckpt", "recover", "read0", 1246+ "read1", "read2", "read3", "read4", "wal_dms", "trxLock"}; 1247+ return (idx < MAX_LOCK_NUM) ? lockName[idx] : "errLock"; 1248+} 1249+ 1250+static void DumpHandleLock(char *dumpBuf, int dumpBufLen) 1251+{ 1252+ char *tmp = dumpBuf; 1253+ u8 *lockStatus = g_lockStatus.lockStatus; 1254+ int availLen = dumpBufLen - 1; 1255+ dumpBuf[availLen] = '\0'; 1256+ for (int i = 0; i < MAX_LOCK_NUM && availLen > DUMP_MAX_STR_LEN; i++) { 1257+ if (lockStatus[i] != NO_LOCK) { 1258+ tmp[0] = '\0'; 1259+ sqlite3_snprintf(availLen, tmp, "<%s, %d>", IdxToLockName((u32)i), lockStatus[i]); 1260+ int len = strlen(tmp); 1261+ tmp += len; 1262+ availLen -= len; 1263+ } 1264+ } 1265+ sqlite3_log(SQLITE_WARNING_DUMP, "[SQLite]BusyLine:%d, idx:%d, type:%d, fileLock:%d, len:%d, handleLocks:%s", 1266+ g_lockStatus.busyLine, g_lockStatus.busyLockIdx, g_lockStatus.busyLockType, g_lockStatus.lockByProcess, 1267+ g_lockStatus.lockLen, tmp != dumpBuf ? dumpBuf : "none"); 1268+} 1269+ 1270+static inline const char *FlockToName(int l_type) 1271+{ 1272+ return l_type == F_RDLCK ? "F_RDLCK" : 1273+ l_type == F_WRLCK ? "F_WRLCK" : 1274+ l_type == F_UNLCK ? "F_UNLCK" : "F_UNKNOWN"; 1275+} 1276+ 1277+static int DumpProcessLocks(int fd, struct flock *lock, const char *lockName, char *dumpBuf, int bufLen) 1278+{ 1279+ dumpBuf[0] = '\0'; 1280+ if (osFcntl(fd, F_GETLK, lock) != SQLITE_OK) { 1281+ sqlite3_log(SQLITE_ERROR, "[SQLite]Get wal file lock ofs %u failed, errno: %d", lock->l_start, errno); 1282+ return 0; 1283+ } 1284+ if (lock->l_type != F_UNLCK) { 1285+ sqlite3_snprintf(bufLen, dumpBuf, "<%s, pid:%u, %s>", lockName, lock->l_pid, FlockToName(lock->l_type)); 1286+ return strlen(dumpBuf); 1287+ } 1288+ return 0; 1289+} 1290+ 1291+static void DumpTrxProcessLocks(unixFile *file, char *dumpBuf, int dumpBufLen) 1292+{ 1293+ unixInodeInfo *inode = file->pInode; 1294+ if (inode == NULL) { 1295+ sqlite3_log(SQLITE_ERROR, "[SQLite]Inode is null!"); 1296+ return; 1297+ } 1298+ sqlite3_log(SQLITE_WARNING_DUMP, "[SQLite]acqLock:%d, dbRef:%d, lockCnt:%d, curLock:%d, processLock:%d", 1299+ file->eFileLock, inode->nRef, inode->nLock, inode->eFileLock, inode->bProcessLock); 1300+ const char *lockName[DB_LOCK_NUM] = {"pending", "reserved", "shared_first"}; 1301+ char *tmp = dumpBuf; 1302+ int availLen = dumpBufLen - 1; 1303+ dumpBuf[availLen] = '\0'; 1304+ for (int i = 0; i < DB_LOCK_NUM && availLen > DUMP_MAX_STR_LEN; i++) { 1305+ off_t ofs = i + PENDING_BYTE; 1306+ off_t lockLen = (ofs == SHARED_FIRST) ? SHARED_SIZE : 1; 1307+ struct flock lock = {.l_type = F_WRLCK, .l_start = ofs, .l_len = lockLen, .l_whence = SEEK_SET}; 1308+ int lockBufLen = DumpProcessLocks(file->h, &lock, lockName[i], tmp, availLen); 1309+ tmp += lockBufLen; 1310+ availLen -= lockBufLen; 1311+ } 1312+ if (tmp != dumpBuf) { 1313+ sqlite3_log(SQLITE_WARNING_DUMP, "[SQLite]Trx locks: %s", dumpBuf); 1314+ } 1315+} 1316+ 1317+static void DumpWalLocks(unixFile *file, u8 walEnabled, char *dumpBuf, int dumpBufLen) 1318+{ 1319+ if (file->pShm == NULL || file->pShm->pShmNode == NULL) { 1320+ sqlite3_log(SQLITE_ERROR, "[SQLite]Wal mode disabled! pShm or pShmNode is NULL"); 1321+ return; 1322+ } 1323+ if (!walEnabled) { 1324+ sqlite3_log(SQLITE_ERROR, "[SQLite] walEnabled false"); 1325+ } 1326+ unixShmNode *pShmNode = file->pShm->pShmNode; 1327+ char *tmp = dumpBuf; 1328+ int availLen = dumpBufLen - 1; 1329+ dumpBuf[availLen] = '\0'; 1330+ for (int i = 0; i < WAL_LOCK_NUM && availLen > DUMP_MAX_STR_LEN; i++) { 1331+ if (i < SQLITE_SHM_NLOCK && pShmNode->aLock[i]) { 1332+ tmp[0] = '\0'; 1333+ sqlite3_snprintf(availLen, tmp, "<%s, %d, tid:%d>", IdxToLockName((u32)i), pShmNode->aLock[i], 1334+ pShmNode->aLockTid[i]); 1335+ int strLen = strlen(tmp); 1336+ tmp += strLen; 1337+ availLen -= strLen; 1338+ } 1339+ off_t ofs = i + WALINDEX_LOCK_OFFSET; 1340+ struct flock lock = {.l_type = F_WRLCK, .l_start = ofs, .l_len = 1, .l_whence = SEEK_SET}; 1341+ int bufLen = DumpProcessLocks(pShmNode->hShm, &lock, IdxToLockName((u32)i), tmp, availLen); 1342+ tmp += bufLen; 1343+ availLen -= bufLen; 1344+ } 1345+ if (tmp != dumpBuf) { 1346+ sqlite3_log(SQLITE_WARNING_DUMP, "[SQLite]Wal locks: %s", dumpBuf); 1347+ } 1348+} 1349+ 1350+static void DumpLocksInfo(unixFile *file, int walEnabled) 1351+{ 1352+ char *dumpBuf = sqlite3Malloc(DUMP_BUF_MAX_LEN); 1353+ if (dumpBuf == NULL) { 1354+ sqlite3_log(SQLITE_ERROR, "[SQLite]Can't alloc bufferSz %d for dump!", DUMP_BUF_MAX_LEN); 1355+ return; 1356+ } 1357+ DumpHandleLock(dumpBuf, DUMP_BUF_MAX_LEN); 1358+ DumpTrxProcessLocks(file, dumpBuf, DUMP_BUF_MAX_LEN); 1359+ DumpWalLocks(file, walEnabled, dumpBuf, DUMP_BUF_MAX_LEN); 1360+ sqlite3_free(dumpBuf); 1361+} 1362+ 1363+#ifndef SQLITE_OMIT_WAL 1364+static void DumpLocksByWal(Wal *pWal) 1365+{ 1366+ if (pWal == NULL) { 1367+ sqlite3_log(SQLITE_ERROR, "Wal ptr is NULL!"); 1368+ return; 1369+ } 1370+ if (pWal->pVfs == NULL || sqlite3_stricmp(pWal->pVfs->zName, "unix") != 0) { 1371+ return; 1372+ } 1373+ DumpLocksInfo((unixFile *)(pWal->pDbFd), 1); 1374+} 1375+#endif /* #ifndef SQLITE_OMIT_WAL */ 1376+ 1377+static void DumpLocksByPager(Pager *pPager) 1378+{ 1379+ if (pPager == NULL) { 1380+ sqlite3_log(SQLITE_ERROR, "Pager ptr is NULL!"); 1381+ return; 1382+ } 1383+ if (pPager->pVfs == NULL || sqlite3_stricmp(pPager->pVfs->zName, "unix") != 0) { 1384+ return; 1385+ } 1386+#ifndef SQLITE_OMIT_WAL 1387+ DumpLocksInfo((unixFile *)(pPager->fd), pPager->pWal != NULL); 1388+#else /* #ifndef SQLITE_OMIT_WAL */ 1389+ DumpLocksInfo((unixFile *)(pPager->fd), 0); 1390+#endif /* #ifndef SQLITE_OMIT_WAL */ 1391+} 1392+#endif /* SQLITE_OS_UNIX */ 1393+ 1394+#ifndef SQLITE_OMIT_WAL 1395+static void walLogCheckpointInfo(Wal *pWal, sqlite3 *db, sqlite3_int64 startTime) { 1396+ sqlite3_int64 endTime; 1397+ sqlite3OsCurrentTimeInt64(db->pVfs, &endTime); 1398+ sqlite3_int64 timeUse = endTime - startTime; 1399+ static sqlite3_int64 lastDumpTime = 0; 1400+ static sqlite3_int64 ckptCnt = 0; 1401+ /* Only when timeUse > 1500ms or wal size > 50MB, default pageSize 4K, 50*1024/4 = 12800 */ 1402+ if (timeUse > 1500 || (pWal->hdr.mxFrame > 12800 && (lastDumpTime - endTime) > 2000)) { 1403+ sqlite3_log(SQLITE_WARNING_DUMP, "[SQLite]Wal try ckpt count %d use time: %lld(ms), wal frame: %u", 1404+ ckptCnt, timeUse, pWal->hdr.mxFrame); 1405+ lastDumpTime = endTime; 1406+ ckptCnt = 0; 1407+ } 1408+ ckptCnt++; 1409+} 1410+#endif 1411+ 1412 // export the symbols 1413 #ifdef SQLITE_EXPORT_SYMBOLS 1414 struct sqlite3_api_routines_extra { 1415-- 14162.47.0.windows.2 1417 1418