bin/186530: ppp(8): bug in the chat implementation (incorrect handling of an expect-send-expect sequences)

[Alexander Zagrebin]

>Number:         186530
>Category:       bin
>Synopsis:       ppp(8): bug in the chat implementation (incorrect handling of an expect-send-expect sequences)
>Confidential:   no
>Severity:       non-critical
>Priority:       low
>Responsible:    freebsd-bugs
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Fri Feb 07 11:30:00 UTC 2014
>Closed-Date:
>Last-Modified:
>Originator:     Alexander Zagrebin
>Release:        FreeBSD 10.0-RELEASE
>Organization:
-
>Environment:
FreeBSD <...> 10.0-RELEASE FreeBSD 10.0-RELEASE #0 r261078: Thu Jan 23 18:17:16 MSK 2014     root@<...>:/usr/obj/usr/src/sys/GENERIC  amd64
>Description:
If we're using an expect-send-expect sequence in a chat script, then under certain conditions the chat script can work incorrectly.

For example, suppose we're using the ppp(8) with the some modem.
We need initialize it before dialing:
Suppose, we have to send "ATCMD1" and to get response "ERROR".
If modem's response isn't "ERROR", then we have to send ATCMD2 and to get response "OK".
In this case we have to use the following chat script:
"TIMEOUT 2 \"\" ATCMD1 ERROR-ATCMD2-OK ATD CONNECT" (see attached ppp.conf)

Suppose, under certain conditions the modem will respond "OK" to the "ATCMD1" command, and "ERROR" to the following "ATCMD2". Such behavior can be simulated with the chat(8) (see "How to repeat the problem").

At such conditions the ppp(8) has to report error while processing the chat script ("Warning: Chat script failed") because "ATCMD2" failed, but it isn't occurs.

After looking a source code I've found, that while processing an expect-send-expect sequence ppp doesn't clear an input buffer between two commands.
So the chat processes the response from the first command instead of second one.
>How-To-Repeat:
To repeat problem you will need the nmdm(4) driver:

# kldload nmdm

On the first console you have to run a modem simulator:

# chat -vs ATCMD1 OK\n ATCMD2 ERROR\n ATD CONNECT < /dev/nmdm0B > /dev/nmdm0B

On the second console you have to run ppp (ppp.conf is attached)

# ppp

See /var/log/ppp.log
It will contain text like this:

ppp[16836]: Phase: Using interface: tun0
ppp[16836]: Phase: deflink: Created in closed state
ppp[16836]: Chat: deflink: Dial attempt 1 of 1
ppp[16836]: Chat: Send: ATCMD1^M
ppp[16836]: Chat: Expect(2): ERROR
ppp[16836]: Chat: Received: ATCMD1^M
ppp[16836]: Chat: Expect timeout
ppp[16836]: Chat: Send: ATCMD2^M
ppp[16836]: Chat: Send: ATD^M
ppp[16836]: Chat: Expect(2): CONNECT
ppp[16836]: Chat: Received: n^MERRORn^MCONNECT

So, despite the fact that "ATCMD2" has returned an "ERROR", the chat script has not stopped with error, but has continued.
>Fix:
There are two possible decisions:
1. To clear an input buffer before sending each command
2. To clear an input buffer at the case of the timeout error while handling an expect-send-expect sequence

I've chose the second one (see attached patch).
As result the log of the patched ppp contains:
ppp[16934]: Phase: Using interface: tun0
ppp[16934]: Phase: deflink: Created in closed state
ppp[16934]: Chat: deflink: Dial attempt 1 of 1
ppp[16934]: Chat: Send: ATCMD1^M
ppp[16934]: Chat: Expect(2): ERROR
ppp[16934]: Chat: Expect timeout
ppp[16934]: Chat: Send: ATCMD2^M
ppp[16934]: Chat: Expect(2): OK
ppp[16934]: Chat: Expect timeout
ppp[16934]: Warning: Chat script failed

So we have an expected behavior now.



Patch attached with submission follows:

patch-ppp-chat.c+++ usr.sbin/ppp/chat.c		2014-02-07 09:07:00.000000000 +0400
@@ -154,6 +154,11 @@ chat_UpdateSet(struct fdescriptor *d, fd
     else {
       /* c->state = CHAT_EXPECT; */
       c->argptr = &arg_term;
+      /*
+        We have to clear an input buffer, because it contains an output from the
+        previous (timeouted) command
+      */
+      c->bufstart = c->bufend;
     }
     c->TimedOut = 0;
   }
    set log Chat
    set device /dev/nmdm0A
    set dial "TIMEOUT 2 \"\" ATCMD1 ERROR-ATCMD2-OK ATD CONNECT"
    open
>Release-Note:
>Audit-Trail:
>Unformatted: