PPP LCP configuration issue
Hi Kristen,
so I added some debug code to actually print the options during the configuration stage. And something seems to be wrong here.
lcp: pppcp_open_event: current state 0:INITIAL
lcp: pppcp_up_event: current state 1:STARTING
lcp: pppcp_initialize_restart_count: current state 1:STARTING
lcp: pppcp_send_configure_request: current state 1:STARTING
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp: pppcp_process_configure_request: current state 6:REQSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp: option 3 len 5 (Authentication-Protocol) c2 23 05
lcp: option 5 len 6 (Magic-Number) 01 ff ef e0
lcp: option 7 len 2 (Protocol-Field-Compression)
lcp: option 8 len 2 (Address-and-Control-Field-Compression)
lcp: pppcp_rcr_plus_event: current state 6:REQSENT
lcp: pppcp_send_configure_ack: current state 6:REQSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp: option 3 len 5 (Authentication-Protocol) c2 23 05
lcp: option 5 len 6 (Magic-Number) 01 ff ef e0
lcp: option 7 len 2 (Protocol-Field-Compression)
lcp: option 8 len 2 (Address-and-Control-Field-Compression)
lcp: pppcp_process_configure_ack: current state 8:ACKSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00 oops -- found acked option 2 we didn't request
lcp: pppcp_rca_event: current state 8:ACKSENT
lcp: pppcp_initialize_restart_count: current state 8:ACKSENT
I see the oops comment here, but we clearly requested the async control character map. So why does it get recognized as not requested? This is clearly a bug and needs to be fixed.
Regards
Marcel
Hi Kristen,
Quoted 27 lines
so I added some debug code to actually print the options during the configuration stage. And something seems to be wrong here.
lcp:
pppcp_open_event: current state 0:INITIAL
lcp:pppcp_up_event: current state 1:STARTING
lcp:pppcp_initialize_restart_count: current state 1:STARTING
lcp:pppcp_send_configure_request: current state 1:STARTING
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp:pppcp_process_configure_request: current state 6:REQSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp: option 3 len 5 (Authentication-Protocol) c2 23 05
lcp: option 5 len 6 (Magic-Number) 01 ff ef e0
lcp: option 7 len 2 (Protocol-Field-Compression)
lcp: option 8 len 2 (Address-and-Control-Field-Compression)
lcp:pppcp_rcr_plus_event: current state 6:REQSENT
lcp:pppcp_send_configure_ack: current state 6:REQSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp: option 3 len 5 (Authentication-Protocol) c2 23 05
lcp: option 5 len 6 (Magic-Number) 01 ff ef e0
lcp: option 7 len 2 (Protocol-Field-Compression)
lcp: option 8 len 2 (Address-and-Control-Field-Compression)
lcp:pppcp_process_configure_ack: current state 8:ACKSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00 oops -- found acked option 2 we didn't request
lcp:pppcp_rca_event: current state 8:ACKSENT
lcp:pppcp_initialize_restart_count: current state 8:ACKSENT
Quoted 3 lines
I see the oops comment here, but we clearly requested the async control character map. So why does it get recognized as not requested? This is clearly a bug and needs to be fixed.
so I added pppdump support to GAtPPP and gsmdial. This allows us to create log files that can be read by pppdump and Wireshark. The method of debugging with strace is just not feasible. The attached log file is one of these. I see a couple of confirmation requests that were send twice in a row. That seems to be wrong. Can you explain what is going on.
Regards
Marcel
K�� ~�}#�!}!}!} }*}"}&} } } } X{~K�� U~�}#�!}!} } }9}"}&} } } } }#}%�#}%}%}&}!�}]+}'}"}(}"��~~�}#�!}"}!} }*}"}&} } } } 1}/~K�� 8~�}#�!}"} } }9}"}&} } } } }#}%�#}%}%}&}!�}]+}'}"}(}"}5�~K�� ~��!
(~K�� D~�}#�!}+}!} }(}!�}]+}-}5~~��# # �! Tdv�F ���EZEUMTS_CHAP_SRVR[�~K�� ~��# 5�=�W��G�/꽃���~K�� ~��# y�~K�� $~��! �
�
�
�
�~K�� *~��! " �
�
�
�
�B~K�� $~��! �
�
�
�
=L~K�� *~��! " �
�
�
�
�~K�� $~��! �
�
�
�
u ~K�� *~��! " �
�
�
�
��~K�� *~��! " �
�
�
�
��~K�� $~��! �
�
�
�
��~K�� *~��! " �
�
�
�
ċ~K� $~��! �
�
�
�
��~K� *~��! " �
�
�
�
aK~K� *~��! " �
�
�
�
aK~K� $~��! �
�
�
�
~K� *~��! " �
�
�
�
~K� $~��! �
�
�
�
D_~K� *~��! " �
�
�
�
�~K� *~��! " �
�
�
�
�~K� $~��! �
�
�
�
�j~K� *~��! " �
�
�
�
c�~K� $~��! �
�
�
�
�8~K� *~��!
" �
�
�
�
�Q~K� *~��!
" �
�
�
�
�Q~K� $~��!
�
�
�
�
_�~K� *~��! " �
�
�
�
�~K� $~��! �
�
�
�
�~K� *~��! " �
�
�
�
��~K�
*~��! " �
�
�
�
��~K� $~��! �
�
�
�
�+~K� *~��!
" �
�
�
�
��~K� $~��!
�
�
�
�
�y~K� *~��! " �
�
�
�
[X~K�
*~��! " �
�
�
�
[X~K� $~��! �
�
�
�
n�~K� *~��! " �
�
�
�
8~K� $~��! �
�
�
�
&�~K� *~��! " �
�
�
�
N�~K� *~��! " �
�
�
�
N�~K� $~��! �
�
�
�
x�~K� *~��! " �
�
�
�
-�~K� $~��! �
�
�
�
0�~K� *~��! " �
�
�
�
�d~K� *~��! " �
�
�
�
�d~K� $~��! �
�
�
�
�@~K� *~��! " �
�
�
�
�$~K� $~��! �
�
�
�
�~K� *~��! " �
�
�
�
��~K� *~��! " �
�
�
�
��~K� $~��! �
�
�
�
I�~K� *~��! " �
�
�
�
��~K� $~��! �
�
�
�
�~K� *~��! " �
�
�
�
m~K� *~��! " �
�
�
�
m~K� $~��! �
�
�
�
�~K� *~��! " �
�
�
�
v-~K� $~��! �
�
�
�
�S~K� *~��! " �
�
�
�
t�~K� *~��! " �
�
�
�
t�~K� $~��! �
�
�
�
f~K� *~��! " �
�
�
�
�~K� $~��! �
�
�
�
R4~K� *~��! " �
�
�
�
�w~K� *~��! " �
�
�
�
�w~K� $~��! ��~~��! �
�
�O~K� *~��! " � � � � Y�~K� ~��! �
�
eP~K� *~��! �~~��! � 0�@G�ƃ@G��!~K� ~��! � � Ł~K� ~��! � 0�@G�ƃ@G����~K� *~��! dX~~��! � 0�@G�ƃ@G��M ~K� ~��! � � q�~K� ~��! �~K� ~��! u'~K�u ~�}#�!}%}!} }$=�~K�v ~�}#�!}&}!} }$��~K�x NO CARRIER
Quoted 29 lines · On Thu, 01 Apr 2010 00:25:45 -0700 Marcel Holtmann <[email protected]> wrote:
Hi Kristen,
so I added some debug code to actually print the options during the configuration stage. And something seems to be wrong here.
lcp:
pppcp_open_event: current state 0:INITIAL
lcp:pppcp_up_event: current state 1:STARTING
lcp:pppcp_initialize_restart_count: current state 1:STARTING
lcp:pppcp_send_configure_request: current state 1:STARTING
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp:pppcp_process_configure_request: current state 6:REQSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp: option 3 len 5 (Authentication-Protocol) c2 23 05
lcp: option 5 len 6 (Magic-Number) 01 ff ef e0
lcp: option 7 len 2 (Protocol-Field-Compression)
lcp: option 8 len 2 (Address-and-Control-Field-Compression)
lcp:pppcp_rcr_plus_event: current state 6:REQSENT
lcp:pppcp_send_configure_ack: current state 6:REQSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp: option 3 len 5 (Authentication-Protocol) c2 23 05
lcp: option 5 len 6 (Magic-Number) 01 ff ef e0
lcp: option 7 len 2 (Protocol-Field-Compression)
lcp: option 8 len 2 (Address-and-Control-Field-Compression)
lcp:pppcp_process_configure_ack: current state 8:ACKSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00 oops -- found acked option 2 we didn't request
lcp:pppcp_rca_event: current state 8:ACKSENT
lcp:pppcp_initialize_restart_count: current state 8:ACKSENT
Quoted 3 lines
I see the oops comment here, but we clearly requested the async control character map. So why does it get recognized as not requested? This is clearly a bug and needs to be fixed.
what is happening is that we are first send a Config-Request with the accm option as our only option. We then receive a Config-Request from the modem, with accm along with several other options requested. We ack the modem's Config-Request and apply the options, and then delete them from the list of options that we need to have. Then the modem response to our original Config-Request with an ack to our accm option. Because we already applied this option and removed it from the list of things we care about, it shows up as an option we didn't request. I think I could just delete the error message, and silently ignore this condition.
Hi Kristen,
Quoted 31 lines
Quoted 27 lines
so I added some debug code to actually print the options during the configuration stage. And something seems to be wrong here.
lcp:
pppcp_open_event: current state 0:INITIAL
lcp:pppcp_up_event: current state 1:STARTING
lcp:pppcp_initialize_restart_count: current state 1:STARTING
lcp:pppcp_send_configure_request: current state 1:STARTING
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp:pppcp_process_configure_request: current state 6:REQSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp: option 3 len 5 (Authentication-Protocol) c2 23 05
lcp: option 5 len 6 (Magic-Number) 01 ff ef e0
lcp: option 7 len 2 (Protocol-Field-Compression)
lcp: option 8 len 2 (Address-and-Control-Field-Compression)
lcp:pppcp_rcr_plus_event: current state 6:REQSENT
lcp:pppcp_send_configure_ack: current state 6:REQSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp: option 3 len 5 (Authentication-Protocol) c2 23 05
lcp: option 5 len 6 (Magic-Number) 01 ff ef e0
lcp: option 7 len 2 (Protocol-Field-Compression)
lcp: option 8 len 2 (Address-and-Control-Field-Compression)
lcp:pppcp_process_configure_ack: current state 8:ACKSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00 oops -- found acked option 2 we didn't request
lcp:pppcp_rca_event: current state 8:ACKSENT
lcp:pppcp_initialize_restart_count: current state 8:ACKSENTQuoted 3 lines
I see the oops comment here, but we clearly requested the async control character map. So why does it get recognized as not requested? This is clearly a bug and needs to be fixed.
Quoted 10 lines
what is happening is that we are first send a Config-Request with the accm option as our only option. We then receive a Config-Request from the modem, with accm along with several other options requested. We ack the modem's Config-Request and apply the options, and then delete them from the list of options that we need to have. Then the modem response to our original Config-Request with an ack to our accm option. Because we already applied this option and removed it from the list of things we care about, it shows up as an option we didn't request. I think I could just delete the error message, and silently ignore this condition.
are these options really negotiated for both sides in common. Or is the negotiation process for each side individual?
Personally I like to keep such error messages. We need to cope with these cases nicely.
Regards
Marcel
Quoted 44 lines · On Fri, 02 Apr 2010 14:01:58 -0700 Marcel Holtmann <[email protected]> wrote:
Hi Kristen,
Quoted 31 lines
Quoted 27 lines
so I added some debug code to actually print the options during the configuration stage. And something seems to be wrong here.
lcp:
pppcp_open_event: current state 0:INITIAL
lcp:pppcp_up_event: current state 1:STARTING
lcp:pppcp_initialize_restart_count: current state 1:STARTING
lcp:pppcp_send_configure_request: current state 1:STARTING
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp:pppcp_process_configure_request: current state 6:REQSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp: option 3 len 5 (Authentication-Protocol) c2 23 05
lcp: option 5 len 6 (Magic-Number) 01 ff ef e0
lcp: option 7 len 2 (Protocol-Field-Compression)
lcp: option 8 len 2 (Address-and-Control-Field-Compression)
lcp:pppcp_rcr_plus_event: current state 6:REQSENT
lcp:pppcp_send_configure_ack: current state 6:REQSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00
lcp: option 3 len 5 (Authentication-Protocol) c2 23 05
lcp: option 5 len 6 (Magic-Number) 01 ff ef e0
lcp: option 7 len 2 (Protocol-Field-Compression)
lcp: option 8 len 2 (Address-and-Control-Field-Compression)
lcp:pppcp_process_configure_ack: current state 8:ACKSENT
lcp: option 2 len 6 (Async-Control-Character-Map) 00 00 00 00 oops -- found acked option 2 we didn't request
lcp:pppcp_rca_event: current state 8:ACKSENT
lcp:pppcp_initialize_restart_count: current state 8:ACKSENTQuoted 3 lines
I see the oops comment here, but we clearly requested the async control character map. So why does it get recognized as not requested? This is clearly a bug and needs to be fixed.
Quoted 10 lines
what is happening is that we are first send a Config-Request with the accm option as our only option. We then receive a Config-Request from the modem, with accm along with several other options requested. We ack the modem's Config-Request and apply the options, and then delete them from the list of options that we need to have. Then the modem response to our original Config-Request with an ack to our accm option. Because we already applied this option and removed it from the list of things we care about, it shows up as an option we didn't request. I think I could just delete the error message, and silently ignore this condition.
Quoted 2 lines
are these options really negotiated for both sides in common. Or is the negotiation process for each side individual?
I think you are right for accm - they are separate. I did have a note to myself to figure out how to do separate transmit accm and receive accm. I'll move that item up the priority list.