Fossil SCM

Improved SQL logging after SIGPIPE. Exponential backoff in the warnings issued when the backoffice process misses its deadline.

drh 2018-07-19 16:27 trunk

Commit f525b6d5e9dcb775a931aa2949684d9b02ce57f959fa3aff4c9982f4be2a5699

Parent a32a92d227be566…

3 files changed +3 -1 +14 +3 -2

M src/backoffice.c

+3 -1

		--- src/backoffice.c
		+++ src/backoffice.c
		@@ -184,10 +184,11 @@
184	184	void backoffice_run(void){
185	185	Lease x;
186	186	sqlite3_uint64 tmNow;
187	187	sqlite3_uint64 idSelf;
188	188	int lastWarning = 0;
	189	+ int warningDelay = 30;
189	190
190	191	if( g.db==0 ){
191	192	fossil_panic("database not open for backoffice processing");
192	193	}
193	194	if( db_transaction_nesting_depth()!=0 ){
		@@ -230,15 +231,16 @@
230	231	backofficeWriteLease(&x);
231	232	db_end_transaction(0);
232	233	if( x.tmCurrent >= tmNow ){
233	234	sqlite3_sleep(1000*(x.tmCurrent - tmNow + 1));
234	235	}else{
235		- if( lastWarning+30 < tmNow ){
	236	+ if( lastWarning+warningDelay < tmNow ){
236	237	fossil_warning(
237	238	"backoffice process %lld still running after %d seconds",
238	239	x.idCurrent, (int)(BKOFCE_LEASE_TIME + tmNow - x.tmCurrent));
239	240	lastWarning = tmNow;
	241	+ warningDelay *= 2;
240	242	}
241	243	sqlite3_sleep(1000);
242	244	}
243	245	}
244	246	return;
245	247

	--- src/backoffice.c
	+++ src/backoffice.c
	@@ -184,10 +184,11 @@
184	void backoffice_run(void){
185	Lease x;
186	sqlite3_uint64 tmNow;
187	sqlite3_uint64 idSelf;
188	int lastWarning = 0;

189
190	if( g.db==0 ){
191	fossil_panic("database not open for backoffice processing");
192	}
193	if( db_transaction_nesting_depth()!=0 ){
	@@ -230,15 +231,16 @@
230	backofficeWriteLease(&x);
231	db_end_transaction(0);
232	if( x.tmCurrent >= tmNow ){
233	sqlite3_sleep(1000*(x.tmCurrent - tmNow + 1));
234	}else{
235	if( lastWarning+30 < tmNow ){
236	fossil_warning(
237	"backoffice process %lld still running after %d seconds",
238	x.idCurrent, (int)(BKOFCE_LEASE_TIME + tmNow - x.tmCurrent));
239	lastWarning = tmNow;

240	}
241	sqlite3_sleep(1000);
242	}
243	}
244	return;
245

	--- src/backoffice.c
	+++ src/backoffice.c
	@@ -184,10 +184,11 @@
184	void backoffice_run(void){
185	Lease x;
186	sqlite3_uint64 tmNow;
187	sqlite3_uint64 idSelf;
188	int lastWarning = 0;
189	int warningDelay = 30;
190
191	if( g.db==0 ){
192	fossil_panic("database not open for backoffice processing");
193	}
194	if( db_transaction_nesting_depth()!=0 ){
	@@ -230,15 +231,16 @@
231	backofficeWriteLease(&x);
232	db_end_transaction(0);
233	if( x.tmCurrent >= tmNow ){
234	sqlite3_sleep(1000*(x.tmCurrent - tmNow + 1));
235	}else{
236	if( lastWarning+warningDelay < tmNow ){
237	fossil_warning(
238	"backoffice process %lld still running after %d seconds",
239	x.idCurrent, (int)(BKOFCE_LEASE_TIME + tmNow - x.tmCurrent));
240	lastWarning = tmNow;
241	warningDelay *= 2;
242	}
243	sqlite3_sleep(1000);
244	}
245	}
246	return;
247

M src/db.c

+14

		--- src/db.c
		+++ src/db.c
		@@ -1886,10 +1886,24 @@
1886	1886	g.localOpen = 0;
1887	1887	assert( g.dbConfig==0 );
1888	1888	assert( g.zConfigDbName==0 );
1889	1889	}
1890	1890
	1891	+/*
	1892	+** Close the database as quickly as possible without unnecessary processing.
	1893	+*/
	1894	+void db_panic_close(void){
	1895	+ if( g.db ){
	1896	+ int rc;
	1897	+ sqlite3_wal_checkpoint(g.db, 0);
	1898	+ rc = sqlite3_close(g.db);
	1899	+ if( g.fSqlTrace ) fossil_trace("-- sqlite3_close(%d)\n", rc);
	1900	+ }
	1901	+ g.db = 0;
	1902	+ g.repositoryOpen = 0;
	1903	+ g.localOpen = 0;
	1904	+}
1891	1905
1892	1906	/*
1893	1907	** Create a new empty repository database with the given name.
1894	1908	**
1895	1909	** Only the schema is initialized. The required VAR tables entries
1896	1910

	--- src/db.c
	+++ src/db.c
	@@ -1886,10 +1886,24 @@
1886	g.localOpen = 0;
1887	assert( g.dbConfig==0 );
1888	assert( g.zConfigDbName==0 );
1889	}
1890














1891
1892	/*
1893	** Create a new empty repository database with the given name.
1894	**
1895	** Only the schema is initialized. The required VAR tables entries
1896

	--- src/db.c
	+++ src/db.c
	@@ -1886,10 +1886,24 @@
1886	g.localOpen = 0;
1887	assert( g.dbConfig==0 );
1888	assert( g.zConfigDbName==0 );
1889	}
1890
1891	/*
1892	** Close the database as quickly as possible without unnecessary processing.
1893	*/
1894	void db_panic_close(void){
1895	if( g.db ){
1896	int rc;
1897	sqlite3_wal_checkpoint(g.db, 0);
1898	rc = sqlite3_close(g.db);
1899	if( g.fSqlTrace ) fossil_trace("-- sqlite3_close(%d)\n", rc);
1900	}
1901	g.db = 0;
1902	g.repositoryOpen = 0;
1903	g.localOpen = 0;
1904	}
1905
1906	/*
1907	** Create a new empty repository database with the given name.
1908	**
1909	** Only the schema is initialized. The required VAR tables entries
1910

M src/main.c

+3 -2

		--- src/main.c
		+++ src/main.c
		@@ -1448,14 +1448,15 @@
1448	1448	** webbrowser opens a connection but never sends the HTTP request
1449	1449	*/
1450	1450	void sigpipe_handler(int x){
1451	1451	#ifndef _WIN32
1452	1452	if( g.fAnyTrace ){
1453		- fprintf(stderr,"/** sigpipe received by subprocess %d **\n", getpid());
	1453	+ fprintf(stderr,"/*** sigpipe received by subprocess %d **\n", getpid());
1454	1454	}
1455	1455	#endif
1456		- fossil_exit(1);
	1456	+ db_panic_close();
	1457	+ exit(1);
1457	1458	}
1458	1459
1459	1460	/*
1460	1461	** Preconditions:
1461	1462	**
1462	1463

	--- src/main.c
	+++ src/main.c
	@@ -1448,14 +1448,15 @@
1448	** webbrowser opens a connection but never sends the HTTP request
1449	*/
1450	void sigpipe_handler(int x){
1451	#ifndef _WIN32
1452	if( g.fAnyTrace ){
1453	fprintf(stderr,"/** sigpipe received by subprocess %d **\n", getpid());
1454	}
1455	#endif
1456	fossil_exit(1);

1457	}
1458
1459	/*
1460	** Preconditions:
1461	**
1462

	--- src/main.c
	+++ src/main.c
	@@ -1448,14 +1448,15 @@
1448	** webbrowser opens a connection but never sends the HTTP request
1449	*/
1450	void sigpipe_handler(int x){
1451	#ifndef _WIN32
1452	if( g.fAnyTrace ){
1453	fprintf(stderr,"/*** sigpipe received by subprocess %d **\n", getpid());
1454	}
1455	#endif
1456	db_panic_close();
1457	exit(1);
1458	}
1459
1460	/*
1461	** Preconditions:
1462	**
1463