234 lines
11 KiB
Plaintext
234 lines
11 KiB
Plaintext
$NetBSD: patch-ac,v 1.2 2006/03/14 13:53:57 rillig Exp $
|
|
|
|
Added more logging and made its appearance more consistent.
|
|
|
|
--- pptp_ctrl.c.orig 2005-07-28 03:15:11.000000000 +0200
|
|
+++ pptp_ctrl.c 2006-03-14 14:26:42.000000000 +0100
|
|
@@ -291,6 +291,7 @@ PPTP_CONN * pptp_conn_open(int inet_sock
|
|
hton16(PPTP_MAX_CHANNELS), hton16(PPTP_FIRMWARE_VERSION),
|
|
PPTP_HOSTNAME, PPTP_VENDOR
|
|
};
|
|
+ log("sending start ctrl conn rqst");
|
|
/* fix this packet, if necessary */
|
|
int idx, rc;
|
|
idx = get_quirk_index();
|
|
@@ -366,6 +367,7 @@ PPTP_CALL * pptp_call_open(PPTP_CONN * c
|
|
packet.phone_len = sizeof(packet.phone_num);
|
|
packet.phone_len = hton16 (packet.phone_len);
|
|
}
|
|
+ log("sending out call rqst");
|
|
if (pptp_send_ctrl_packet(conn, &packet, sizeof(packet))) {
|
|
pptp_reset_timer();
|
|
call->state.pns = PNS_WAIT_REPLY;
|
|
@@ -393,6 +395,7 @@ void pptp_call_close(PPTP_CONN * conn, P
|
|
/* don't check state against WAIT_DISCONNECT... allow multiple disconnect
|
|
* requests to be made.
|
|
*/
|
|
+ log("sending call clear rqst");
|
|
pptp_send_ctrl_packet(conn, &rqst, sizeof(rqst));
|
|
pptp_reset_timer();
|
|
call->state.pns = PNS_WAIT_DISCONNECT;
|
|
@@ -427,7 +430,7 @@ void pptp_conn_close(PPTP_CONN * conn, u
|
|
for (i = 0; i < vector_size(conn->call); i++)
|
|
pptp_call_close(conn, vector_get_Nth(conn->call, i));
|
|
/* now close connection */
|
|
- log("Closing PPTP connection");
|
|
+ log("Closing PPTP connection (sending stop ctrl conn rqst)");
|
|
pptp_send_ctrl_packet(conn, &rqst, sizeof(rqst));
|
|
pptp_reset_timer(); /* wait 60 seconds for reply */
|
|
conn->conn_state = CONN_WAIT_STOP_REPLY;
|
|
@@ -706,7 +709,17 @@ int ctrlp_disp(PPTP_CONN * conn, void *
|
|
hton16(PPTP_MAX_CHANNELS), hton16(PPTP_FIRMWARE_VERSION),
|
|
PPTP_HOSTNAME, PPTP_VENDOR };
|
|
int idx, rc;
|
|
- log("Received Start Control Connection Request");
|
|
+ log("Received Start Control Connection Request: v%d rcode %d ecode %d fcap %x bcap %x chans %d fw %x host `%.64s' vendor `%.64s'",
|
|
+ ntoh16(packet->version),
|
|
+ packet->result_code,
|
|
+ packet->error_code,
|
|
+ ntoh32(packet->framing_cap),
|
|
+ ntoh32(packet->bearer_cap),
|
|
+ ntoh16(packet->max_channels),
|
|
+ ntoh16(packet->firmware_rev),
|
|
+ packet->hostname,
|
|
+ packet->vendor
|
|
+ );
|
|
/* fix this packet, if necessary */
|
|
idx = get_quirk_index();
|
|
if (idx != -1 && pptp_fixups[idx].start_ctrl_conn) {
|
|
@@ -719,9 +732,11 @@ int ctrlp_disp(PPTP_CONN * conn, void *
|
|
reply.version = packet->version;
|
|
/* protocol version not supported */
|
|
reply.result_code = hton8(5);
|
|
+ log("sending start ctrl conn reply (NAK)");
|
|
pptp_send_ctrl_packet(conn, &reply, sizeof(reply));
|
|
pptp_reset_timer(); /* give sender a chance for a retry */
|
|
} else { /* same or greater version */
|
|
+ log("sending start ctrl conn reply (ACK)");
|
|
if (pptp_send_ctrl_packet(conn, &reply, sizeof(reply))) {
|
|
conn->conn_state = CONN_ESTABLISHED;
|
|
log("server connection ESTABLISHED.");
|
|
@@ -735,7 +750,18 @@ int ctrlp_disp(PPTP_CONN * conn, void *
|
|
{
|
|
struct pptp_start_ctrl_conn *packet =
|
|
(struct pptp_start_ctrl_conn *) buffer;
|
|
- log("Received Start Control Connection Reply");
|
|
+ log("Received Start Control Connection Reply: v%d rcode %d ecode %d fcap %x bcap %x chans %d fw %x host `%.64s' vendor `%.64s'",
|
|
+ ntoh16(packet->version),
|
|
+ packet->result_code,
|
|
+ packet->error_code,
|
|
+ ntoh32(packet->framing_cap),
|
|
+ ntoh32(packet->bearer_cap),
|
|
+ ntoh16(packet->max_channels),
|
|
+ ntoh16(packet->firmware_rev),
|
|
+ packet->hostname,
|
|
+ packet->vendor
|
|
+ );
|
|
+
|
|
if (conn->conn_state == CONN_WAIT_CTL_REPLY) {
|
|
/* XXX handle collision XXX [see rfc] */
|
|
if (ntoh16(packet->version) != PPTP_VERSION) {
|
|
@@ -778,14 +804,21 @@ int ctrlp_disp(PPTP_CONN * conn, void *
|
|
/* ----------- STANDARD Stop-Session MESSAGES ------------ */
|
|
case PPTP_STOP_CTRL_CONN_RQST:
|
|
{
|
|
+ struct pptp_stop_ctrl_conn *packet =
|
|
+ (struct pptp_stop_ctrl_conn *) buffer;
|
|
/* conn_state should be CONN_ESTABLISHED, but it could be
|
|
* something else */
|
|
struct pptp_stop_ctrl_conn reply = {
|
|
PPTP_HEADER_CTRL(PPTP_STOP_CTRL_CONN_RPLY),
|
|
hton8(1), hton8(PPTP_GENERAL_ERROR_NONE), 0
|
|
};
|
|
- log("Received Stop Control Connection Request.");
|
|
+ log("Received Stop Control Connection Request: reason %d err %d reserved %d",
|
|
+ packet->reason_result,
|
|
+ packet->error_code,
|
|
+ ntoh16(packet->reserved1)
|
|
+ );
|
|
if (conn->conn_state == CONN_IDLE) break;
|
|
+ log("sending stop ctrl conn reply");
|
|
if (pptp_send_ctrl_packet(conn, &reply, sizeof(reply))) {
|
|
if (conn->callback != NULL)
|
|
conn->callback(conn, CONN_CLOSE_RQST);
|
|
@@ -796,7 +829,13 @@ int ctrlp_disp(PPTP_CONN * conn, void *
|
|
}
|
|
case PPTP_STOP_CTRL_CONN_RPLY:
|
|
{
|
|
- log("Received Stop Control Connection Reply.");
|
|
+ struct pptp_stop_ctrl_conn *packet =
|
|
+ (struct pptp_stop_ctrl_conn *) buffer;
|
|
+ log("Received Stop Control Connection Reply: reason %d err %d reserved %d",
|
|
+ packet->reason_result,
|
|
+ packet->error_code,
|
|
+ ntoh16(packet->reserved1)
|
|
+ );
|
|
/* conn_state should be CONN_WAIT_STOP_REPLY, but it
|
|
* could be something else */
|
|
if (conn->conn_state == CONN_IDLE) break;
|
|
@@ -842,9 +881,23 @@ int ctrlp_disp(PPTP_CONN * conn, void *
|
|
hton32(PPTP_CONNECT_SPEED),
|
|
hton16(PPTP_WINDOW), hton16(PPTP_DELAY), 0
|
|
};
|
|
- log("Received Outgoing Call Request.");
|
|
+ log("Received Outgoing Call Request: id %x csn %d minbps %d max %d bearer %x framing %x rsize %d delay %d plen %d rsv1 %d phone `%.64s' sub `%.64s'",
|
|
+ ntoh16(packet->call_id),
|
|
+ ntoh16(packet->call_sernum),
|
|
+ ntoh32(packet->bps_min),
|
|
+ ntoh32(packet->bps_max),
|
|
+ ntoh32(packet->bearer),
|
|
+ ntoh32(packet->framing),
|
|
+ ntoh16(packet->recv_size),
|
|
+ ntoh16(packet->delay),
|
|
+ ntoh16(packet->phone_len),
|
|
+ ntoh16(packet->reserved1),
|
|
+ packet->phone_num,
|
|
+ packet->subaddress
|
|
+ );
|
|
/* XXX PAC: eventually this should make an outgoing call. XXX */
|
|
reply.result_code = hton8(7); /* outgoing calls verboten */
|
|
+ log("sending out call reply (NAK)");
|
|
pptp_send_ctrl_packet(conn, &reply, sizeof(reply));
|
|
break;
|
|
}
|
|
@@ -854,7 +907,17 @@ int ctrlp_disp(PPTP_CONN * conn, void *
|
|
(struct pptp_out_call_rply *)buffer;
|
|
PPTP_CALL * call;
|
|
u_int16_t callid = ntoh16(packet->call_id_peer);
|
|
- log("Received Outgoing Call Reply.");
|
|
+ log("Received Outgoing Call Reply: id %x peer %d result %d err %d cause %x speed %d rsize %d delay %d channel %x",
|
|
+ ntoh16(packet->call_id),
|
|
+ ntoh16(packet->call_id_peer),
|
|
+ packet->result_code,
|
|
+ packet->error_code,
|
|
+ ntoh16(packet->cause_code),
|
|
+ ntoh32(packet->speed),
|
|
+ ntoh16(packet->recv_size),
|
|
+ ntoh16(packet->delay),
|
|
+ ntoh32(packet->channel)
|
|
+ );
|
|
if (!vector_search(conn->call, (int) callid, &call)) {
|
|
log("PPTP_OUT_CALL_RPLY received for non-existant call: "
|
|
"peer call ID (us) %d call ID (them) %d.",
|
|
@@ -908,12 +971,16 @@ int ctrlp_disp(PPTP_CONN * conn, void *
|
|
PPTP_HEADER_CTRL(PPTP_CALL_CLEAR_NTFY), packet->call_id,
|
|
1, PPTP_GENERAL_ERROR_NONE, 0, 0, {0}
|
|
};
|
|
- log("Received Call Clear Request.");
|
|
+ log("Received Call Clear Request: cid %d reserved %d",
|
|
+ ntoh16(packet->call_id),
|
|
+ ntoh16(packet->reserved1)
|
|
+ );
|
|
if (vector_contains(conn->call, ntoh16(packet->call_id))) {
|
|
PPTP_CALL * call;
|
|
vector_search(conn->call, ntoh16(packet->call_id), &call);
|
|
if (call->callback != NULL)
|
|
call->callback(conn, call, CALL_CLOSE_RQST);
|
|
+ log("sending call clear ntfy");
|
|
pptp_send_ctrl_packet(conn, &reply, sizeof(reply));
|
|
pptp_call_destroy(conn, call);
|
|
log("Call closed (RQST) (call id %d)", (int) call->call_id);
|
|
@@ -924,8 +991,13 @@ int ctrlp_disp(PPTP_CONN * conn, void *
|
|
{
|
|
struct pptp_call_clear_ntfy *packet =
|
|
(struct pptp_call_clear_ntfy *)buffer;
|
|
- log("Call disconnect notification received (call id %d)",
|
|
- ntoh16(packet->call_id));
|
|
+ log("received call clear ntfy: cid %d result %d err %d cause %x reserved %d",
|
|
+ ntoh16(packet->call_id),
|
|
+ packet->result_code,
|
|
+ packet->error_code,
|
|
+ ntoh16(packet->cause_code),
|
|
+ ntoh16(packet->reserved1)
|
|
+ );
|
|
if (vector_contains(conn->call, ntoh16(packet->call_id))) {
|
|
PPTP_CALL * call;
|
|
ctrlp_error(packet->result_code, packet->error_code,
|
|
@@ -944,12 +1016,12 @@ int ctrlp_disp(PPTP_CONN * conn, void *
|
|
/* this is really dealt with in the HDLC deencapsulation, anyway. */
|
|
struct pptp_set_link_info *packet =
|
|
(struct pptp_set_link_info *)buffer;
|
|
- /* log it. */
|
|
- log("PPTP_SET_LINK_INFO received from peer_callid %u",
|
|
- (unsigned int) ntoh16(packet->call_id_peer));
|
|
- log(" send_accm is %08lX, recv_accm is %08lX",
|
|
- (unsigned long) ntoh32(packet->send_accm),
|
|
- (unsigned long) ntoh32(packet->recv_accm));
|
|
+ log("received set link info: peer %x res %d send %x recv %x\n",
|
|
+ ntoh16(packet->call_id_peer),
|
|
+ ntoh16(packet->reserved1),
|
|
+ ntoh32(packet->send_accm),
|
|
+ ntoh32(packet->recv_accm)
|
|
+ );
|
|
if (!(ntoh32(packet->send_accm) == 0 &&
|
|
ntoh32(packet->recv_accm) == 0))
|
|
warn("Non-zero Async Control Character Maps are not supported!");
|
|
@@ -1051,6 +1123,7 @@ static void pptp_handle_timer()
|
|
} else { /* ka_state == NONE */ /* send keep-alive */
|
|
struct pptp_echo_rqst rqst = {
|
|
PPTP_HEADER_CTRL(PPTP_ECHO_RQST), hton32(global.conn->ka_id) };
|
|
+ log("sending echo request: %d", global.conn->ka_id);
|
|
pptp_send_ctrl_packet(global.conn, &rqst, sizeof(rqst));
|
|
global.conn->ka_state = KA_OUTSTANDING;
|
|
}
|