problem with LCP negotiation -- (pppd and iseries, modem config?) - PPP

This is a discussion on problem with LCP negotiation -- (pppd and iseries, modem config?) - PPP ; Hello all! I'm working on debugging a problem encountered when trying to use ppp to connect a linux box and an iseries server. Based on the information I have from logs it looks like a problem with the modem config ...

+ Reply to Thread
Results 1 to 3 of 3

Thread: problem with LCP negotiation -- (pppd and iseries, modem config?)

  1. problem with LCP negotiation -- (pppd and iseries, modem config?)

    Hello all!

    I'm working on debugging a problem encountered when trying to use ppp
    to connect a linux box and an iseries server. Based on the information
    I have from logs it looks like a problem with the modem config on the
    linux box. But, I have not been able to figure out any solution to
    this problem.

    Anywho, here goes...

    By comparing the iseries and pppd log it looks as if the linux box is
    not receiving the LCP packets from the iseries (or, the data is
    mangled). The iseries sends configAcks but no reply is sent from the
    linux box. pppd complains about "bit 7 always set to 0", maybe this is
    part of the problem? (I've google'd it without a whole lot of help
    found)

    When the following is sent from the iseries, linux receives different
    data (as shown in the slsnif log above).

    3 S 20 00000000 14:16:42.62309 PPP FF UI
    C021 (LCP)
    LCP . . . . . : Code: 01 (Configure Request) ID: FE
    Length: 16
    Option . . . . : Type: 02 (Async Map) Length:
    6 Async Map: 00000000
    Option . . . . : Type: 05 (Magic Number) Length:
    6 Magic Number: 43A49CE6
    Data . . . . . : FF03C02101FE0010 0206000000000506 43A49CE6
    *..{..............u.W *

    slsnif picked this up as (taken from "Device -->" line shown below):

    "7E7F03 40210101 ..."

    So the real question is why is there a difference in the data received
    on the linux box?

    The output from pppd looks like this:

    ------------ start pppd output -----------------
    [cschult@anvl scripts]$ ./mypppd.sh
    pppd options in effect:
    debug # (from command line)
    -detach # (from command line)
    dump # (from command line)
    /dev/ttyp0 # (from command line)
    38400 # (from command line)
    lock # (from /etc/ppp/options)
    connect mychat.sh # (from command line)
    crtscts # (from command line)
    modem # (from command line)
    asyncmap 0 # (from command line)
    mtu 1500 # (from command line)
    lcp-restart 4 # (from command line)
    lcp-max-configure 20 # (from command line)
    ipcp-accept-local # (from command line)
    ipcp-accept-remote # (from command line)

    Synchronizing ports...Done!
    ATZ
    OK
    ATDT2055
    CONNECT
    Serial connection established.
    using channel 1
    Using interface ppp0
    Connect: ppp0 <--> /dev/ttyp0
    sent [LCP ConfReq id=0x1
    ]
    .... repeated 19 times ...

    LCP: timeout sending Config-Requests
    Connection terminated.
    Receive serial link is not 8-bit clean:
    Problem: all had bit 7 set to 0

    -------------- end pppd output -----------------

    the chat file looks like:

    ------------ start chat file -------------------
    '' ATZ
    OK ATDT2055
    CONNECT ''

    -------------- end chat file -------------------

    The log from slsnif looks looks like:

    ------------ start slsnif log ------------------
    Host --> A (41)

    Host --> T (54)

    Host --> Z (5a)

    Host --> (0d)

    Device --> A (41) T (54) Z (5a) (0d) (0d) (0a) O (4f) K
    (4b) (0d) (0a)

    Host --> A (41)

    Host --> T (54)

    Host --> D (44)

    Host --> T (54)

    Host --> 2 (32)

    Host --> 0 (30)

    Host --> 5 (35)

    Host --> 5 (35)

    Host --> (0d)

    Device --> A (41) T (54) D (44) T (54) 2 (32) 0 (30) 5 (35) 5 (35)
    (0d)

    Device --> (0a) C (43) O (4f) N (4e) N (4e) E (45) C (43) T (54)
    (20) 3 (33) 8 (38) 4 (34) 0 (30) 0 (30) (0d)

    Host --> (0d)

    Host --> ~ (7e) (ff) } (7d) # (23) (c0) ! (21) } (7d) ! (21) }
    (7d) ! (21) } (7d) (20) } (7d) 4 (34) } (7d) " (22) } (7d) &
    (26) } (7d) (20) } (7d) (20) } (7d) (20) } (7d)
    (20) } (7d) % (25) } (7d) & (26) (bb) (d0)

    Host --> ' (91) u (75) } (7d) ' (27) } (7d) " (22) } (7d) ( (28) }
    (7d) " (22) e (65) } (7d) 4 (34) ~ (7e)

    Host --> ~ (7e) (ff) } (7d) # (23) (c0) ! (21) } (7d) ! (21) }
    (7d) ! (21) } (7d) (20) } (7d) 4 (34) } (7d) " (22) } (7d) &
    (26) } (7d) (20) } (7d) (20) } (7d) (20) } (7d)
    (20) } (7d) % (25) } (7d) & (26) (bb) (d0)

    Host --> ' (91) u (75) } (7d) ' (27) } (7d) " (22) } (7d) ( (28) }
    (7d) " (22) e (65) } (7d) 4 (34) ~ (7e)

    Device --> (7f) } (7d) # (23) @ (40) ! (21) } (7d) ! (21) } (7d)
    ! (21) } (7d) (20) } (7d) 0 (30) } (7d) " (22)

    ....and many many more messages that look like this.
    -------------- end slsnif log ------------------

    I also have a log from the iseries system I'm trying to connect to. It
    looks like this:

    ------------------ start iseries log -----------
    15:02:33.303 === LCP ENTERING ESTABLISH PHASE

    15:02:33.303 ==> LCP/REQSENT CfgReq/0x01 id 0x72 len 16 00000000>
    15:02:36.336 ==> LCP/REQSENT CfgReq/0x01 id 0x73 len 16 00000000>
    15:02:39.720 ==> LCP/REQSENT CfgReq/0x01 id 0x74 len 16 00000000>
    15:02:43.453 ==> LCP/REQSENT CfgReq/0x01 id 0x75 len 16 00000000>
    15:02:47.536 ==> LCP/REQSENT CfgReq/0x01 id 0x76 len 16 00000000>
    15:02:52.023 ==> LCP/REQSENT CfgReq/0x01 id 0x77 len 16 00000000>
    15:02:56.806 ==> LCP/REQSENT CfgReq/0x01 id 0x78 len 16 00000000>
    15:03:01.940 ==> LCP/REQSENT CfgReq/0x01 id 0x79 len 16 00000000>
    15:03:07.423 ==> LCP/REQSENT CfgReq/0x01 id 0x7A len 16 00000000>
    15:03:11.684 <== LCP/REQSENT CfgReq/0x01 id 0x01 len 20 00000000>
    15:03:11.685 ==> LCP/REQSENT CfgAck/0x02 id 0x01 len 20 00000000>
    15:03:13.257 ==> LCP/ACKSENT CfgReq/0x01 id 0x7B len 16 00000000>
    15:03:19.440 ==> LCP/ACKSENT CfgReq/0x01 id 0x7C len 16 00000000>
    15:03:25.973 ==> LCP/ACKSENT CfgReq/0x01 id 0x7D len 16 00000000>
    15:03:32.857 ==> LCP/ACKSENT CfgReq/0x01 id 0x7E len 16 00000000>
    15:03:40.090 ==> LCP/ACKSENT CfgReq/0x01 id 0x7F len 16 00000000>
    15:03:41.678 <== LCP/ACKSENT CfgReq/0x01 id 0x01 len 20 00000000>
    15:03:41.679 ==> LCP/ACKSENT CfgAck/0x02 id 0x01 len 20 00000000>
    15:03:47.674 ==> LCP/ACKSENT CfgReq/0x01 id 0x80 len 16 00000000>
    15:03:55.608 ==> LCP/ACKSENT CfgReq/0x01 id 0x81 len 16 00000000>
    15:04:03.891 ==> LCP/ACKSENT CfgReq/0x01 id 0x82 len 16 00000000>
    15:04:11.677 <== LCP/ACKSENT CfgReq/0x01 id 0x01 len 20 00000000>
    15:04:11.677 ==> LCP/ACKSENT CfgAck/0x02 id 0x01 len 20 00000000>
    15:04:12.525 ==> LCP/ACKSENT CfgReq/0x01 id 0x83 len 16 00000000>
    15:04:21.508 ==> LCP/ACKSENT CfgReq/0x01 id 0x84 len 16 00000000>
    15:04:30.842 ==> LCP/ACKSENT CfgReq/0x01 id 0x85 len 16 00000000>
    15:04:40.525 === DBG: fsm_timeout(249) REQUEST RETRY COUNTER == 0.

    15:04:40.526 === NOTE: LCP TERMINATING. NO RESPONSE FROM PEER AFTER
    SENDING MAXIMUM 20 CONFIG-REQUESTS.

    -------------------- end iseries log -----------


    I really hope someone can help with this problem and I hope I haven't
    gotten too far ahead of myself with all the logs in this post.

    Thanks to anyone who can take a look at this!

    -chris


  2. Re: problem with LCP negotiation -- (pppd and iseries, modem config?)

    jchris.work@gmail.com writes:
    > By comparing the iseries and pppd log it looks as if the linux box is
    > not receiving the LCP packets from the iseries (or, the data is
    > mangled). The iseries sends configAcks but no reply is sent from the
    > linux box. pppd complains about "bit 7 always set to 0", maybe this is
    > part of the problem? (I've google'd it without a whole lot of help
    > found)


    Ding ding! Yep; that'll cause severe and unfixable problems.

    The serial link is misconfigured for 7-bit communications at some
    point. It could be the serial ports (set up for a default of 7 data
    bits, even parity, one stop bit -- an old and evil UNIX default) or
    the modems (some modems have strange defaults).

    > When the following is sent from the iseries, linux receives different
    > data (as shown in the slsnif log above).

    [...]
    > slsnif picked this up as (taken from "Device -->" line shown below):
    >
    > "7E7F03 40210101 ..."


    That narrows it down, as that should have been this:

    7E FF 03 C0 21 01 01

    In other words, the path from the iseries device to the Linux device
    is corrupt; it's resetting the top bit.

    > So the real question is why is there a difference in the data received
    > on the linux box?
    >
    > The output from pppd looks like this:


    It's not pppd.

    > Receive serial link is not 8-bit clean:
    > Problem: all had bit 7 set to 0


    That pretty much summarizes the problem. PPP is defined to work on
    8-bit links -- only. It can't work on 7 bit links.

    Either the modem's default configuration is bad (get a programmer's
    reference manual for your modem), or the serial port on that iseries
    box is misconfigured.

    --
    James Carlson, KISS Interop
    Sun Microsystems / 1 Network Drive 71.234W Vox +1 781 442 2084
    MS UBUR02-212 / Burlington MA 01803-2757 42.497N Fax +1 781 442 1677

  3. Re: problem with LCP negotiation -- (pppd and iseries, modem config?)

    jchris.work@gmail.com writes:

    >Hello all!


    >I'm working on debugging a problem encountered when trying to use ppp
    >to connect a linux box and an iseries server. Based on the information
    >I have from logs it looks like a problem with the modem config on the
    >linux box. But, I have not been able to figure out any solution to
    >this problem.


    >Anywho, here goes...


    >By comparing the iseries and pppd log it looks as if the linux box is
    >not receiving the LCP packets from the iseries (or, the data is
    >mangled). The iseries sends configAcks but no reply is sent from the
    >linux box. pppd complains about "bit 7 always set to 0", maybe this is
    >part of the problem? (I've google'd it without a whole lot of help
    >found)


    Yes, it id definitely the problem. ppp negotiations MUST be 8 bit.
    You either have the serial port set up badly or you set up your modem
    badly to use 7 bit communication. You MUST set them up for full 8 bit
    operation. (of course maybe it is the modem at the other end).

    setserial -a /dev/ttyS0

    Or perhaps you sent the modem the wrong setup command (I have no idea of
    which modem youhave or what the correct command for it would be. On one of
    mine it would be
    AT\B3
    but I do not think that is universal.





    >When the following is sent from the iseries, linux receives different
    >data (as shown in the slsnif log above).


    >3 S 20 00000000 14:16:42.62309 PPP FF UI
    > C021 (LCP)
    > LCP . . . . . : Code: 01 (Configure Request) ID: FE
    > Length: 16
    > Option . . . . : Type: 02 (Async Map) Length:
    >6 Async Map: 00000000
    > Option . . . . : Type: 05 (Magic Number) Length:
    >6 Magic Number: 43A49CE6
    > Data . . . . . : FF03C02101FE0010 0206000000000506 43A49CE6
    > *..{..............u.W *


    >slsnif picked this up as (taken from "Device -->" line shown below):


    >"7E7F03 40210101 ..."


    Youp the 8the bit ( bit #7 counting from 0) is being discarded.


    >So the real question is why is there a difference in the data received
    >on the linux box?


    One or the other modems is dropping the bit. One or the other comptuers is
    sropping the bit, or one of the modems is defective.



    ..............
    >I really hope someone can help with this problem and I hope I haven't
    >gotten too far ahead of myself with all the logs in this post.


    It is fine. better too many than too few.

    >Thanks to anyone who can take a look at this!


    >-chris



+ Reply to Thread