Article delegate-en/3372 of [1-5169] on the server localhost:119
  upper oldest olders older1 this newer1 newers latest
search
[Top/Up] [oldest] - [Older+chunk] - [Newer+chunk] - [newest + Check]
[Reference:<_A3369@delegate-en.ML_>]
Newsgroups: mail-lists.delegate-en

[DeleGate-En] Re: Working with CFI
06 Jul 2006 23:38:55 GMT feedback@delegate.org (Yutaka Sato)
The DeleGate Project


Hi Xavier,

I uploaded dg9_2_3-pre9x.zip which includes probes to trace the behavior
of the CFI process on Windows, at pub/DeleGate/alpha/.
I wish you to use pre9x for testing instead of pre9.

Well, I could "reproduce" the problem inserting a code into src/process.c:
callFilter() to cause 0xC0000005 "STATUS_ACCESS_VIOLATION" (SIGSEGV).
(I used a simple code *(char*)0 = 0;)

Then I got a pop-up windows by WinXP to ask bug-reporting which includes
"technical information" as this:

  Exception Information
  Code: 0xc00000005  Flags: 0x00000000
  Record: 0x0000000000000000  Address: 0x000000000000523182

The "Address: .. 523xxx" shows the violation occured around callFilter().
Please let me know this Address field when you get the error.

Studying your log, I thought the location where SIGSEGV happens is limited
into narrow range.  It must be from line 67 to 69 in process.c.
If the CFI process does not reach this section, then the caller process
must block waiting the fread() from a pipe.
If the CFI process passes this section, then the "#### clearConnPTR:..."
message must be logged by clearConnPTR().

A possible but unlikely senario I can figure out is that malloc() returns
somewhat illegal or insufficient area which causes SIGSEGV when written
by fread().
Another possible but unlikely senario is clearing character pointer in
clearConnPTR() caseus SIGSEGV due to alignment problem or so.

Anyway, if it is caused on your machine with 9.2.3-pre9x, the log will
give us great hints.


    [9.2.3-pre9/src/process.c]
    32	#define CLEAR(m) (Conn->m = 0)
    33	
    34	static void clearConnPTR(Connection *Conn)
    35	{
    36		CLEAR(sv_toServ);
    37		CLEAR(cl_user);
    38		CLEAR(cl_FromCbuff);
    39		CLEAR(gw_path);
    40		CLEAR(ht_LockedByClient);
    44	if( D_REQUESTtag.ut_addr ) sv1log("#### clearConnPTR: clearing D_REQUEST\n");
    45		UTclear(&D_REQUESTtag);
    46	}
    47	
    48	int callFilter(Connection *Conn,int ac,const char *av[])
    49	{	int ein,eout,rcc;
    50		int fio[2];
    51		FILE *in,*out;
    52		const char *args;
    53		int sock;
    54		int rcode;
    55	
    60		sscanf(av[2],"%d/%d/%d/%d",&fio[0],&fio[1],&ein,&eout);
    61		in = fdopen(fio[0],"r");
    62		close(fio[1]);
    63	
    64		rcc = fread(Conn,1,sizeof(Connection),in);
    65		if( Conn->cl_reqbuf ){
    66			Conn->cl_reqbuf = (char*)malloc(Conn->cl_reqbufsize);
    67			fread(Conn->cl_reqbuf,1,Conn->cl_reqbufsize,in);
    68		}
    69		clearConnPTR(Conn);
    70		fdopenLogFile(Conn->fi_logfd);



---- the log of normal code execution ----
07/07 07:46:36.47 [2124] 1+1: HTTP => (www:80) GET /delegate/ HTTP/1.0^M
07/07 07:46:36.47 [2124] 1+1: #HT11 FORCE HTTP/1.1 or Connection:keep-alive
(WIN) 46:36.781 [2124] spawn() = 1580 [1700], children(alive=1,total=1) 0.016s
07/07 07:46:36.78 [1700] 0+0: -- callFilter(127B58-12E618) 12343CB8 107D34+118072 12B4B8:BD6EC0 4:4:27328 523919 5235C0
07/07 07:46:36.78 [1700] 0+0: -- callFilter qbuf=FD2910+118072
07/07 07:46:36.78 [1700] 0+0: -- callFilter qbuf=110000/00000X
07/07 07:46:36.78 [1700] 0+0: #### clearConnPTR: clearing D_REQUEST
07/07 07:46:36.78 [1700] 0+0: -- callFilter args=90/90 BD34E0
07/07 07:46:36.78 [1700] 0+0: #### execFilter[FTOCL] CFI
07/07 07:46:36.80 [1700] 0+0: ## CFI/http ##
07/07 07:46:36.80 [2124] 1+1: #HT11 SERVER ver[HTTP/1.1] conn[close]
07/07 07:46:36.80 [2124] 1+1: HTTP/1.1 200 Content-{Type:text/html Encoding:[/] Leng:16197} Server:DeleGate
(WIN) 46:36.796 [2124] -- SOCKET recv(30)=0 error=0 [0.000]
07/07 07:46:36.80 [2124] 1+1: Content-Length: 16197 -> 16197 (16325 - 128)
07/07 07:46:36.81 [1700] 0+0: systemFilter[33,0]: c:/cygwin/bin/cat.exe -n

---- the log of forced SIGSEGV in process.c:callFilter() ----
07/07 07:47:20.42 [2084] 1+1: HTTP => (www:80) GET /delegate/ HTTP/1.0^M
07/07 07:47:20.42 [2084] 1+1: #HT11 FORCE HTTP/1.1 or Connection:keep-alive
(WIN) 47:20.781 [2084] spawn() = 1676 [2332], children(alive=1,total=1) 0.016s
07/07 07:47:20.78 [2332] 0+0: -- callFilter(127B58-12E618) 12343CB8 108CF4+118072 12B4B8:BD6BB0 4:4:27328 523390 523030
07/07 07:47:20.78 [2332] 0+0: -- callFilter qbuf=FD3230+118072
07/07 07:47:20.80 [2332] 0+0: -- callFilter qbuf=110000/00000X
07/07 07:47:20.81 [2084] 1+1: #HT11 SERVER ver[HTTP/1.1] conn[close]
07/07 07:47:20.81 [2084] 1+1: HTTP/1.1 200 Content-{Type:text/html Encoding:[/] Leng:16197} Server:DeleGate
(WIN) 47:20.812 [2084] -- SOCKET recv(27)=0 error=0 [0.000]
07/07 07:47:20.81 [2084] 1+1: Content-Length: 16197 -> 16197 (16325 - 128)
07/07 07:49:43.55 [2084] 1+1: ClosedOnTimeout(1): time=1152226183/1152226070 ppid=3028/3028 pid=2084/2084
07/07 07:49:43.55 [2084] 1+1: ## stop relay-4: FWRITE(16197)=5120, SIGPIPE=0, client seems dead
07/07 07:49:43.55 [2084] 1+1: ## HTTP RESPONSE CLOSE: NO (client dead)
07/07 07:49:43.55 [2084] 1+1: ClientEOF: flush_respbuff.FAILED
07/07 07:49:43.55 [2084] 1+1: HTTP transmitted: 104head+00000/0000fbody=>0txt+0bin->-1/16197, 21i/2o/0f/142.8
07/07 07:49:43.55 [2084] 1+1: #HT11 EOF from the server
07/07 07:49:43.55 [2084] 1+1: #HT11 close svsokcs[28,29]
07/07 07:49:43.55 [2084] 1+1: HCKA:[0] closed -- x:external filter
(WIN) 49:43.546 [2084] wait3(N) = 1676 [2332] C0000005, children(alive=0,total=1) 0.00s
----

Cheers,
Yutaka
--
  9 9   Yutaka Sato <y.sato@delegate.org> http://delegate.org/y.sato/
 ( ~ )  National Institute of Advanced Industrial Science and Technology
_<   >_ 1-1-4 Umezono, Tsukuba, Ibaraki, 305-8568 Japan
Do the more with the less -- B. Fuller


diff -cr delegate9.2.3-pre9/rary/windows.c delegate9.2.3-pre9x/rary/windows.c
*** delegate9.2.3-pre9/rary/windows.c	Fri Jun 30 17:04:41 2006
--- delegate9.2.3-pre9x/rary/windows.c	Fri Jul  7 07:13:15 2006
***************
*** 2373,2379 ****
  	Etime = Time() - Start;
  
  	if( 0 <= xpid || 1 <= Etime )
! 	LE("wait3(%s) = %d [%d] %d, children(alive=%d,total=%d) %.2fs",
  		tv?"N":"H",xpid,cpid,xstatus,nalive,ntotal,Etime);
  /*
  	if( 0 <= xpid )
--- 2373,2379 ----
  	Etime = Time() - Start;
  
  	if( 0 <= xpid || 1 <= Etime )
! 	LE("wait3(%s) = %d [%d] %X, children(alive=%d,total=%d) %.2fs",
  		tv?"N":"H",xpid,cpid,xstatus,nalive,ntotal,Etime);
  /*
  	if( 0 <= xpid )
diff -cr delegate9.2.3-pre9/src/filter.c delegate9.2.3-pre9x/src/filter.c
*** delegate9.2.3-pre9/src/filter.c	Wed Jul  5 16:05:43 2006
--- delegate9.2.3-pre9x/src/filter.c	Fri Jul  7 07:13:19 2006
***************
*** 2660,2665 ****
--- 2660,2666 ----
  			Finish(-1);
  		}
  	}else{
+ 		bzero(Conn,sizeof(Connection));
  		pid = spawnFilter(Conn,1,tofd,fileno(out),(iFUNCP)callFsystem,command);
  	}
  
diff -cr delegate9.2.3-pre9/src/process.c delegate9.2.3-pre9x/src/process.c
*** delegate9.2.3-pre9/src/process.c	Sat Jun 24 16:04:41 2006
--- delegate9.2.3-pre9x/src/process.c	Fri Jul  7 07:43:28 2006
***************
*** 62,70 ****
--- 62,82 ----
  	close(fio[1]);
  
  	rcc = fread(Conn,1,sizeof(Connection),in);
+ 
+ 	sv1log("-- callFilter(%X-%X) %X %X+%d %X:%X %d:%d:%d %X %X\n",
+ 		Conn,&Conn[1],
+ 		Conn->cx_magic,Conn->cl_reqbuf,Conn->cl_reqbufsize,
+ 		&D_REQUESTtag,D_REQUESTtag.ut_addr,
+ 		sizeof(int),sizeof(char*),sizeof(Connection),
+ 		clearConnPTR,callFilter
+ 	);
  	if( Conn->cl_reqbuf ){
  		Conn->cl_reqbuf = (char*)malloc(Conn->cl_reqbufsize);
+ 		sv1log("-- callFilter qbuf=%X+%d\n",
+ 			Conn->cl_reqbuf,Conn->cl_reqbufsize);
+ 		rcc =
  		fread(Conn->cl_reqbuf,1,Conn->cl_reqbufsize,in);
+ 		sv1log("-- callFilter qbuf=%d/%d\n",rcc,Conn->cl_reqbufsize);
  	}
  	clearConnPTR(Conn);
  	fdopenLogFile(Conn->fi_logfd);
***************
*** 76,81 ****
--- 88,94 ----
  		args = NULL;
  		rcc = 0;
  	}
+ 	sv1log("-- callFilter args=%d/%d %X\n",rcc,Conn->fi_arglen,args);
  
  	ClientSock = -1;
  	if( Conn->fi_issock ){
diff -cr delegate9.2.3-pre9/src/version.c delegate9.2.3-pre9x/src/version.c
*** delegate9.2.3-pre9/src/version.c	Wed Jul  5 14:41:40 2006
--- delegate9.2.3-pre9x/src/version.c	Fri Jul  7 07:13:28 2006
***************
*** 16,23 ****
  #include "log.h"
  
  #define NAME	"DeleGate"
! #define VERSION	"9.2.3-pre9"
! #define DATE	"July 5, 2006"
  #define DSTATUS	"BETA"
  #define AUTHOR	"Yutaka Sato"
  #define A_ORG	"National Institute of Advanced Industrial Science and Technology"
--- 16,23 ----
  #include "log.h"
  
  #define NAME	"DeleGate"
! #define VERSION	"9.2.3-pre9x"
! #define DATE	"July 7, 2006"
  #define DSTATUS	"BETA"
  #define AUTHOR	"Yutaka Sato"
  #define A_ORG	"National Institute of Advanced Industrial Science and Technology"

  admin search upper oldest olders older1 this newer1 newers latest
[Top/Up] [oldest] - [Older+chunk] - [Newer+chunk] - [newest + Check]
@_@V