pkgsrc/net/pptp/patches/patch-ac

$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;
     }