[Asterisk-Dev] chan_skinny Cisco 7970 problems

Jared Mauch jared at puck.nether.net
Thu Mar 18 23:21:55 MST 2004


	So, i've been having some problems with chan_skinny
and my 7970 (latest cvs)

here's what I have going on (packet dumps shown as seen inside
get_input)

	periodically the phone will properly register, but i'm
unable to place any calls to it.  placing some calls from it seem to work
fine.

	The phone is running TERM70.5-0-0-6S 

    -- Starting Skinny session from x.x.x.27
0x60 0x00 0x00 0x00 
    -- skinny get_input dlen= 96, res=4
0x00 0x00 0x00 0x00 0x20 0x00 0x00 0x00 0x02 0x00 0x00 0x00 0x31 0x34 0x3a 0x20 
0x4e 0x61 0x6d 0x65 0x3d 0x53 0x45 0x50 0x30 0x30 0x30 0x45 0x33 0x38 0x33 0x34 
0x43 0x31 0x41 0x33 0x20 0x4c 0x6f 0x61 0x64 0x3d 0x35 0x2e 0x30 0x28 0x30 0x2e 
0x36 0x53 0x29 0x20 0x4c 0x61 0x73 0x74 0x3d 0x43 0x4d 0x2d 0x63 0x6c 0x6f 0x73 
0x65 0x64 0x2d 0x54 0x43 0x50 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 
0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 
0x00 0x00 0x00 0x00 
    -- Recieved AlarmMessage
0x30 0x00 0x00 0x00 
    -- skinny get_input dlen= 48, res=4
0x00 0x00 0x00 0x00 0x01 0x00 0x00 0x00 0x53 0x45 0x50 0x30 0x30 0x30 0x45 0x33 
0x38 0x33 0x34 0x43 0x31 0x41 0x33 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 
0xXX 0xXX 0xXX 0x1b 0x36 0x75 0x00 0x00 0x03 0x00 0x00 0x00 0x00 0x00 0x00 0x00 
0x04 0x00 0x00 0x80 
    -- Device SEP000E3834C1A3 is attempting to register
    -- Requesting capabilities
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x2b 0x00 0x00 0x00 0x02 0x00 0x00 0x00 
RECEIVED UNKNOWN MESSAGE TYPE:  2b
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x02 0x00 0x00 0x00 0xac 0x0d 0x00 0x00 
0x04 0x00 0x00 0x00 
    -- skinny get_input dlen= 4, res=4
0x00 0x00 0x00 0x00 0x0e 0x00 0x00 0x00 
    -- Buttontemplate requested
0x04 0x00 0x00 0x00 
    -- skinny get_input dlen= 4, res=4
0x00 0x00 0x00 0x00 0x28 0x00 0x00 0x00 
    -- Recieved SoftKey Template Request
0x04 0x00 0x00 0x00 
    -- skinny get_input dlen= 4, res=4
0x00 0x00 0x00 0x00 0x25 0x00 0x00 0x00 
    -- Received SoftKeySetReq
0x04 0x00 0x00 0x00 
    -- skinny get_input dlen= 4, res=4
0x00 0x00 0x00 0x00 0x0c 0x00 0x00 0x00 
RECEIVED UNKNOWN MESSAGE TYPE:  c
0x04 0x00 0x00 0x00 
    -- skinny get_input dlen= 4, res=4
0x00 0x00 0x00 0x00 0x0d 0x00 0x00 0x00 
    -- Received Time/Date Request
0x78 0x00 0x00 0x00 
    -- skinny get_input dlen= 120, res=4
0x00 0x00 0x00 0x00 0x10 0x00 0x00 0x00 0x07 0x00 0x00 0x00 0x10 0x00 0x00 0x00 
0x5a 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x0c 0x00 0x00 0x00 
0x5a 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x0f 0x00 0x00 0x00 
0x5a 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x0b 0x00 0x00 0x00 
0x5a 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x04 0x00 0x00 0x00 
0x28 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x02 0x00 0x00 0x00 

Mar 19 06:13:02 WARNING[-1347363920]: chan_skinny.c:2313 get_input: Skinny Client sent less data than expected (96 != 124).
Mar 19 06:13:02 NOTICE[-1347363920]: chan_skinny.c:2364 skinny_session: Skinny Session returned: -1/Success



	here is a successful registration:

    -- Starting Skinny session from x.x.x.27
0x30 0x00 0x00 0x00 
    -- skinny get_input dlen= 48, res=4
0x00 0x00 0x00 0x00 0x01 0x00 0x00 0x00 0x53 0x45 0x50 0x30 0x30 0x30 0x45 0x33 
0x38 0x33 0x34 0x43 0x31 0x41 0x33 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 
0xXX 0xXX 0xXX 0x1b 0x36 0x75 0x00 0x00 0x03 0x00 0x00 0x00 0x00 0x00 0x00 0x00 
0x04 0x00 0x00 0x80 
    -- Device SEP000E3834C1A3 is attempting to register
    -- Requesting capabilities
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x2b 0x00 0x00 0x00 0x02 0x00 0x00 0x00 
RECEIVED UNKNOWN MESSAGE TYPE:  2b
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x02 0x00 0x00 0x00 0xac 0x0d 0x00 0x00 
0x04 0x00 0x00 0x00 
    -- skinny get_input dlen= 4, res=4
0x00 0x00 0x00 0x00 0x0e 0x00 0x00 0x00 
    -- Buttontemplate requested
0x04 0x00 0x00 0x00 
    -- skinny get_input dlen= 4, res=4
0x00 0x00 0x00 0x00 0x28 0x00 0x00 0x00 
    -- Recieved SoftKey Template Request
0x04 0x00 0x00 0x00 
    -- skinny get_input dlen= 4, res=4
0x00 0x00 0x00 0x00 0x25 0x00 0x00 0x00 
    -- Received SoftKeySetReq
0x04 0x00 0x00 0x00 
    -- skinny get_input dlen= 4, res=4
0x00 0x00 0x00 0x00 0x0c 0x00 0x00 0x00 
RECEIVED UNKNOWN MESSAGE TYPE:  c
0x04 0x00 0x00 0x00 
    -- skinny get_input dlen= 4, res=4
0x00 0x00 0x00 0x00 0x0d 0x00 0x00 0x00 
    -- Received Time/Date Request
0x78 0x00 0x00 0x00 
    -- skinny get_input dlen= 120, res=4
0x00 0x00 0x00 0x00 0x10 0x00 0x00 0x00 0x07 0x00 0x00 0x00 0x10 0x00 0x00 0x00 
0x5a 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x0c 0x00 0x00 0x00 
0x5a 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x0f 0x00 0x00 0x00 
0x5a 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x0b 0x00 0x00 0x00 
0x5a 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x04 0x00 0x00 0x00 
0x28 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x02 0x00 0x00 0x00 
0x28 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x19 0x00 0x00 0x00 
0x28 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 
    -- Received CapabilitiesRes
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x0b 0x00 0x00 0x00 0x01 0x00 0x00 0x00 
    -- Received LineStateReq
0x04 0x00 0x00 0x00 
    -- skinny get_input dlen= 4, res=4
0x00 0x00 0x00 0x00 0x09 0x00 0x00 0x00 
RECEIVED UNKNOWN MESSAGE TYPE:  9
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x0a 0x00 0x00 0x00 0x01 0x00 0x00 0x00 
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x0a 0x00 0x00 0x00 0x02 0x00 0x00 0x00 
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x0a 0x00 0x00 0x00 0x03 0x00 0x00 0x00 
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x0a 0x00 0x00 0x00 0x04 0x00 0x00 0x00 
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x0a 0x00 0x00 0x00 0x05 0x00 0x00 0x00 
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x0a 0x00 0x00 0x00 0x06 0x00 0x00 0x00 
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x0a 0x00 0x00 0x00 0x07 0x00 0x00 0x00 
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x0a 0x00 0x00 0x00 0x08 0x00 0x00 0x00 
0x08 0x00 0x00 0x00 
    -- skinny get_input dlen= 8, res=4
0x00 0x00 0x00 0x00 0x0a 0x00 0x00 0x00 0x09 0x00 0x00 0x00 


here's what i get when i place a call to it:

    -- Found device: jared
    -- skinny_call(Skinny/2981 at jared-2)
** I receive ringback on my 7960 i'm dialing from, but
** the 7970 never rings.
skinny_hangup(Skinny/2981 at jared-2) on 2981 at jared


	If I press the button next to the line 2981 in my phone,
I get this in the CLI:

0x10 0x00 0x00 0x00 
    -- skinny get_input dlen= 16, res=4
0x00 0x00 0x00 0x00 0x26 0x00 0x00 0x00 0x02 0x00 0x00 0x00 0x01 0x00 0x00 0x00 
0x00 0x00 0x00 0x00 
RECEIVED UNKNOWN MESSAGE TYPE:  26

	The phone does not go off-hook as a result.

	I've attached my diffs for the debugging as reference.
Parts of this patch I'd like to go into chan_skinny as it puts
the debugging (when enabled) in the logs instead of printfs that go
nowhere if running as a daemon.

	I'm looking for any help one can provide here, i'm a bit lost
poking around at the code and packet dumps right now..

	- jared


-- 
Jared Mauch  | pgp key available via finger from jared at puck.nether.net
clue++;      | http://puck.nether.net/~jared/  My statements are only mine.
-------------- next part --------------
Index: channels/chan_skinny.c
===================================================================
RCS file: /usr/cvsroot/asterisk/channels/chan_skinny.c,v
retrieving revision 1.32
diff -u -r1.32 chan_skinny.c
--- channels/chan_skinny.c	15 Mar 2004 09:14:16 -0000	1.32
+++ channels/chan_skinny.c	19 Mar 2004 06:19:31 -0000
@@ -731,7 +731,7 @@
 	while(d) {
 		if (!strcasecmp(d->name, device)) {
 			if (skinnydebug) {
-				printf("Found device: %s\n", d->name);
+				ast_verbose(VERBOSE_PREFIX_3 "Found device: %s\n", d->name);
 			}
 			/* Found the device */
 			l = d->lines;
@@ -1256,7 +1256,7 @@
         timeout = 0;
         if (res < 0) {
 			if (skinnydebug)
-				printf("Skinny(%s@%s): waitfordigit returned < 0\n", l->name, l->parent->name);
+				ast_verbose(VERBOSE_PREFIX_3 "Skinny(%s@%s): waitfordigit returned < 0\n", l->name, l->parent->name);
         	ast_indicate(chan, -1);
 			ast_hangup(chan);
             return NULL;
@@ -1826,7 +1826,8 @@
 	time_t timer;
 	struct tm *cmtime;
 	pthread_t t;
-	
+	skinny_req *tx_req;
+
 	if ( (!s->device) && (req->e != REGISTER_MESSAGE && req->e != ALARM_MESSAGE)) {
 		ast_log(LOG_WARNING, "Client sent message #%d without first registering.\n", req->e);
 		free(req);
@@ -1837,11 +1838,11 @@
 	switch(req->e)	{
 	case ALARM_MESSAGE:
 		if (skinnydebug)
-			printf("Recieved AlarmMessage\n");
+			ast_verbose(VERBOSE_PREFIX_3 "Recieved AlarmMessage\n");
 		break;
 	case REGISTER_MESSAGE:
 		if (skinnydebug)
-			printf("Device %s is attempting to register\n", req->data.reg.name);
+			ast_verbose(VERBOSE_PREFIX_3 "Device %s is attempting to register\n", req->data.reg.name);
 		res = skinny_register(req, s);	
 		if (!res) {
 			ast_log(LOG_ERROR, "Rejecting Device %s: Device not found\n", req->data.reg.name);
@@ -1865,7 +1866,7 @@
 		req->data.regack.secondaryKeepAlive = keep_alive;
 		transmit_response(s, req);
 		if (skinnydebug)
-			printf ("Requesting capabilities\n");
+			ast_verbose(VERBOSE_PREFIX_3 "Requesting capabilities\n");
 		memset(req, 0, SKINNY_MAX_PACKET);
 		req->len = 4;
 		req->e = CAPABILITIES_REQ_MESSAGE;
@@ -1884,23 +1885,23 @@
 		case STIMULUS_REDIAL:
 			// XXX how we gonna deal with redial ?!?!
 			if (skinnydebug) {
-				printf("Recieved Stimulus: Redial(%d)\n", stimulusInstance);
+				ast_verbose(VERBOSE_PREFIX_3 "Recieved Stimulus: Redial(%d)\n", stimulusInstance);
 			}
 			break;
 		case STIMULUS_SPEEDDIAL:
 			if (skinnydebug) {
-				printf("Recieved Stimulus: SpeedDial(%d)\n", stimulusInstance);
+				ast_verbose(VERBOSE_PREFIX_3 "Recieved Stimulus: SpeedDial(%d)\n", stimulusInstance);
 			}
 			break;
 		case STIMULUS_HOLD:
 			// Easy enough
 			if (skinnydebug) {
-				printf("Recieved Stimulus: Hold(%d)\n", stimulusInstance);
+				ast_verbose(VERBOSE_PREFIX_3 "Recieved Stimulus: Hold(%d)\n", stimulusInstance);
 			}
 			break;
 		case STIMULUS_TRANSFER:
 			if (skinnydebug) {
-				printf("Recieved Stimulus: Transfer(%d)\n", stimulusInstance);
+				ast_verbose(VERBOSE_PREFIX_3 "Recieved Stimulus: Transfer(%d)\n", stimulusInstance);
 			}
 			transmit_tone(s, SKINNY_DIALTONE);
 				
@@ -1912,18 +1913,18 @@
 		case STIMULUS_FORWARDNOANSWER:
 			// Gonna be fun
 			if (skinnydebug) {
-				printf("Recieved Stimulus: Forward (%d)\n", stimulusInstance);
+				ast_verbose(VERBOSE_PREFIX_3 "Recieved Stimulus: Forward (%d)\n", stimulusInstance);
 			}
 			break;
 		case STIMULUS_DISPLAY:
 			// XXX Not sure
 			if (skinnydebug) {
-				printf("Recieved Stimulus: Display(%d)\n", stimulusInstance);
+				ast_verbose(VERBOSE_PREFIX_3 "Recieved Stimulus: Display(%d)\n", stimulusInstance);
 			}
 			break;
 		case STIMULUS_LINE:
 			if (skinnydebug) {
-				printf("Recieved Stimulus: Line(%d)\n", stimulusInstance);
+				ast_verbose(VERBOSE_PREFIX_3 "Recieved Stimulus: Line(%d)\n", stimulusInstance);
 			}		
 			sub = find_subchannel_by_line(s->device->lines);
 			transmit_speaker_mode(s, 1);  // Turn on
@@ -1937,7 +1938,7 @@
 		break;
 	case VERSION_REQ_MESSAGE:
 		if (skinnydebug)
-			printf ("Version Request\n");
+			ast_verbose(VERBOSE_PREFIX_3 "Version Request\n");
 		memset(req, 0, SKINNY_MAX_PACKET);
 		req->len = sizeof(version_res_message)+4;
 		req->e = VERSION_RES_MESSAGE;
@@ -1946,7 +1947,7 @@
 		break;
 	case SERVER_REQUEST_MESSAGE:
 		if (skinnydebug)
-			printf ("Recieved Server Request\n");
+			ast_verbose(VERBOSE_PREFIX_3 "Recieved Server Request\n");
 		memset(req, 0, SKINNY_MAX_PACKET);
 		req->len = sizeof(server_res_message)+4;
 		req->e = SERVER_RES_MESSAGE;
@@ -1958,7 +1959,7 @@
 		break;
 	case BUTTON_TEMPLATE_REQ_MESSAGE:
 		if (skinnydebug)
-			printf ("Buttontemplate requested\n");
+			ast_verbose(VERBOSE_PREFIX_3 "Buttontemplate requested\n");
 		memset(req, 0, SKINNY_MAX_PACKET);
 		req->len = sizeof(button_template_res_message)+4;
 		req->e = BUTTON_TEMPLATE_RES_MESSAGE;	
@@ -1973,7 +1974,7 @@
 		break;
 	case SOFT_KEY_SET_REQ_MESSAGE:
 		if (skinnydebug)
-			printf ("Received SoftKeySetReq\n");
+			ast_verbose(VERBOSE_PREFIX_3 "Received SoftKeySetReq\n");
 		memset(req, 0, SKINNY_MAX_PACKET);
 		req->len = sizeof(soft_key_sets)+4;
 		req->e = SOFT_KEY_SET_RES_MESSAGE;
@@ -1988,7 +1989,7 @@
 		break;
 	case SOFT_KEY_TEMPLATE_REQ_MESSAGE:
 		if (skinnydebug)
-			printf ("Recieved SoftKey Template Request\n");
+			ast_verbose(VERBOSE_PREFIX_3 "Recieved SoftKey Template Request\n");
 		memset(req, 0, SKINNY_MAX_PACKET);
 		req->len = sizeof(soft_key_template)+4;
 		req->e = SOFT_KEY_TEMPLATE_RES_MESSAGE;
@@ -2003,27 +2004,29 @@
 		break;
 	case TIME_DATE_REQ_MESSAGE:
 		if (skinnydebug)
-			printf ("Received Time/Date Request\n");
-		memset(req, 0, SKINNY_MAX_PACKET);
-		req->len = sizeof(definetimedate_message)+4;
-		req->e = DEFINETIMEDATE_MESSAGE;
+			ast_verbose(VERBOSE_PREFIX_3 "Received Time/Date Request\n");
+		tx_req = malloc(SKINNY_MAX_PACKET);
+		memset(tx_req, 0, SKINNY_MAX_PACKET);
+		tx_req->len = sizeof(definetimedate_message)+4;
+		tx_req->e = DEFINETIMEDATE_MESSAGE;
 		timer=time(NULL);
 		cmtime = localtime(&timer);
-		req->data.definetimedate.year = cmtime->tm_year+1900;
-		req->data.definetimedate.month = cmtime->tm_mon+1;
-		req->data.definetimedate.dayofweek = cmtime->tm_wday;
-		req->data.definetimedate.day = cmtime->tm_mday;
-		req->data.definetimedate.hour = cmtime->tm_hour;
-		req->data.definetimedate.minute = cmtime->tm_min;
-		req->data.definetimedate.seconds = cmtime->tm_sec;
-		transmit_response(s, req);
+		tx_req->data.definetimedate.year = cmtime->tm_year+1900;
+		tx_req->data.definetimedate.month = cmtime->tm_mon+1;
+		tx_req->data.definetimedate.dayofweek = cmtime->tm_wday;
+		tx_req->data.definetimedate.day = cmtime->tm_mday;
+		tx_req->data.definetimedate.hour = cmtime->tm_hour;
+		tx_req->data.definetimedate.minute = cmtime->tm_min;
+		tx_req->data.definetimedate.seconds = cmtime->tm_sec;
+		transmit_response(s, tx_req);
+		free(tx_req);
 		break;
 	case SPEED_DIAL_STAT_REQ_MESSAGE:
 		/* Not really sure how Speed Dial's are different than the 
 		   Softkey templates */
 		speedDialNum = req->data.speeddialreq.speedDialNumber;
 //		if (skinnydebug)
-//			printf ("Recieved SpeedDialStatReq: %d\n", speedDialNum);
+//			ast_verbose(VERBOSE_PREFIX_3 "Recieved SpeedDialStatReq: %d\n", speedDialNum);
 		memset(req, 0, SKINNY_MAX_PACKET);
 		req->len = sizeof(speed_dial_stat_res_message)+4;
 		req->e = SPEED_DIAL_STAT_RES_MESSAGE;
@@ -2038,7 +2041,7 @@
 	case LINE_STATE_REQ_MESSAGE:
 		lineNumber = req->data.line.lineNumber;
 		if (skinnydebug)
-			printf ("Received LineStateReq\n");
+			ast_verbose(VERBOSE_PREFIX_3 "Received LineStateReq\n");
 		memset(req, 0, SKINNY_MAX_PACKET);
 		req->len = sizeof(line_stat_res_message)+4;
 		req->e = LINE_STAT_RES_MESSAGE;	
@@ -2062,7 +2065,7 @@
 		break;
 	case CAPABILITIES_RES_MESSAGE:
 		if (skinnydebug)
-			printf ("Received CapabilitiesRes\n");	
+			ast_verbose(VERBOSE_PREFIX_3 "Received CapabilitiesRes\n");	
 		// zien wat ie kan en verwerken (handshake)
 		break;
 	case KEEP_ALIVE_MESSAGE:
@@ -2118,7 +2121,7 @@
 		sub->parent->hookstate = SKINNY_ONHOOK;
 		transmit_callstate(s, s->device->lines->instance, sub->parent->hookstate,sub->callid);
 	    if (skinnydebug)
-			printf("Skinny %s@%s went on hook\n",sub->parent->name, sub->parent->parent->name);
+			ast_verbose(VERBOSE_PREFIX_3 "Skinny %s@%s went on hook\n",sub->parent->name, sub->parent->parent->name);
 	    if (sub->rtp) {
  //         transmit_modify_request(sub);
         }
@@ -2158,7 +2161,7 @@
 	case KEYPAD_BUTTON_MESSAGE:
 		digit = req->data.keypad.button;
 		if (skinnydebug) {
-			printf("Collected digit: [%d]\n", digit);
+			ast_verbose(VERBOSE_PREFIX_3 "Collected digit: [%d]\n", digit);
 		}
 		f.frametype = AST_FRAME_DTMF;
 		if (digit == 14) {
@@ -2187,7 +2190,7 @@
 		printf("Recieved Open Recieve Channel Ack\n");
 		status = req->data.openrecievechannelack.status;
 		if (status) {
-			ast_log(LOG_ERROR, "Open Recieve Channel Failure\n");
+			ast_log(LOG_ERROR, "Open Recieve Channel Failure (status = %d)\n", status);
 			break;
 		}
 		memcpy(addr, req->data.openrecievechannelack.ipAddr, sizeof(addr));
@@ -2254,6 +2257,28 @@
 	ast_mutex_unlock(&sessionlock);
 }
 
+void print_in_hex(unsigned char *message, int msgsize)
+{
+        int x;
+        for (x =0;x<msgsize;x++)
+        {
+                if ((message[x] > 0) && (message[x] < 26))
+                        fprintf(stderr, "0x%-2.2x ", message[x]);
+                else if (message[x] == 0)
+                        fprintf(stderr, "0x%-2.2x ", message[x]);
+                else
+                        fprintf(stderr, "0x%-2.2x ", message[x]);
+                if ((x != 0) && (((x+1) %16) == 0))
+                        fprintf(stderr, "\n");
+        }
+        fprintf(stderr, "\n");
+
+}
+
+
+/*
+ * Get data from skinny client
+ */
 static int get_input(struct skinnysession *s)  
 {  
  
@@ -2271,15 +2296,21 @@
  	} else if (res > 0) {
 		memset(s->inbuf,0,sizeof(s->inbuf));
 		res = read(s->fd, s->inbuf, 4);
-		if (res != 4) {
-			ast_log(LOG_WARNING, "Skinny Client sent less data than expected.\n");
+		if (res < 4) {
+			ast_log(LOG_WARNING, "Skinny Client sent less data than expected. (%d != 4)\n", res);
 			return -1;
 		}
 		dlen = *(int *)s->inbuf;
+		print_in_hex(s->inbuf, res);
+                if (skinnydebug) {
+                        ast_verbose(VERBOSE_PREFIX_3 "skinny get_input dlen= %d, res=%d\n", dlen, res);
+                }
+
 		res = read(s->fd, s->inbuf+4, dlen+4);
-		ast_mutex_unlock(&s->lock);
+		print_in_hex(s->inbuf+4, res);
+	 	ast_mutex_unlock(&s->lock);
 		if (res != (dlen+4)) {
-			ast_log(LOG_WARNING, "Skinny Client sent less data than expected.\n");
+			ast_log(LOG_WARNING, "Skinny Client sent less data than expected (%d != %d).\n", res, (dlen+4));
 			return -1;
 		} 
  
@@ -2330,7 +2361,7 @@
 			return NULL;
 		} 
 	}
-	ast_log(LOG_NOTICE, "Skinny Session returned: %s\n", strerror(errno));
+	ast_log(LOG_NOTICE, "Skinny Session returned: %d/%s\n", res, strerror(errno));
 	destroy_session(s);
 	return 0;
 }
@@ -2381,7 +2412,7 @@
 	
 	
 	if (skinnydebug)
-		printf("killing accept thread\n");
+		ast_verbose(VERBOSE_PREFIX_3 "skinny: killing accept thread\n");
 	
 	close(as);
 	return 0;


More information about the asterisk-dev mailing list