Sierra Wireless in Lenovo X61, pppd escaped

[Sebastian Koch]

hi,
on my lenovo X61 with 1199:6813 Sierra Wireless, Inc. the pppd escaped uncontrolled after starting the connection.
That means the umtsmon complained about a failed ppp-connection but the pppd is still running in the background.
The pppd-connection is working fine. But the umtsmon has lost the control.

umtsmon is build by the cvs-repository (last update is from 2010/05/24)
LANG=de_DE@euro

Here is the log from ./umtsmon -v4
umtsmon version 0.9.72 .
##P1 t=632: setVerbosity: '4'
##P2 t=632: set verbosity level to 4
##P2 t=632: set PPP verbosity level to 1
##P2 t=632: Settings will be saved in : '/home/seb/.umtsmon'
##P4 t=632: loadTranslator('qt', 'de_DE@EURO')
##P4 t=632:  .. found in '/usr/lib/qt3/translations'
##P4 t=632: loadTranslator('umtsmon', 'de_DE@EURO')
##P4 t=632:  .. found in 'i18n'
##P3 t=632: Will use specified (de_DE@EURO) locale for QT-internal strings
##P3 t=632: Will use specified (de_DE@EURO) locale for umtsmon strings
##P2 t=632: Warning with Memory Name: WelcomeMsg, Message: Willkommen bei UMTSmon!
##P3 t=632:   Message not shown due to user preference
##P3 t=632: ObserverManager COPY constructor
##P4 t=632: DummyConnection::DummyConnection(void)
##P3 t=632: Device creation for type 0x00000001 requested
##P2 t=632: Profile::Profile('')
##P2 t=632:   finally created profile for 'alice'
##P2 t=632: UIState::newConnectionState(0) callback called
##P2 t=635: ***UIState::update(void), state=0
##P2 t=635:

UIState::setState(0 -> 1)
##P3 t=635: TheDeviceManagerSingleton::setupDevice(void)
##P3 t=635: TheDeviceManagerSingleton::readFromConfigFile()
##P4 t=635: read PPP port from config: '/dev/ttyUSB0'.
##P4 t=635: read AT port from config: '/dev/ttyUSB2'.
##P4 t=635: read device type from config: 0x51322402
##P3 t=635: Complete config read from file - good :-)
##P3 t=635: Start iterating through all AutoDetectors

##P4 t=635: Kernel: 'Linux version 2.6.27.45-0.1-pae (geeko@buildhost) (gcc version 4.3.2  (SUSE Linux) ) #1 SMP 2010-02-22 16:49:47 +0100'
##P3 t=635: AutoDetectBase::go() for 'Device creation from supplied parameters'
##P3 t=635:  AutoDetectBase::createDevice() for CardType 0x51322402
##P3 t=635: Device creation for type 0x51322402 requested
##P2 t=635: Profile::Profile('')
##P2 t=635:   finally created profile for 'alice'
##P3 t=635: Device: probing port '/dev/ttyUSB0' for AT commands
##P3 t=635: TempSerialPort::TempSerialPort()
##P3 t=635: Serial::openDev('/dev/ttyUSB0') as FD 7 - Serial instance 0xbfe4191c
##P4 t=635: Query sends the following mesage: 'AT'
##P2 t=635: Device port '/dev/ttyUSB0': no response to "AT", return code 5
##P3 t=635: Device: probing port '/dev/ttyUSB0' failed
##P3 t=635: TempSerialPort::~TempSerialPort()
##P3 t=635: SerialPort::closeDev() for FD 7
##P3 t=635: Device: probing port '/dev/ttyUSB2' for AT commands
##P3 t=635: TempSerialPort::TempSerialPort()
##P3 t=636: Serial::openDev('/dev/ttyUSB2') as FD 7 - Serial instance 0xbfe4191c
##P4 t=636: Query sends the following mesage: 'AT'
##P4 t=636: answer 1:'OK'
##P3 t=636: Got Query::OK from port
##P3 t=636: Device: probing port '/dev/ttyUSB2' successful
##P3 t=636: TempSerialPort::~TempSerialPort()
##P3 t=636: SerialPort::closeDev() for FD 7
##P3 t=636: set AT  serial to '/dev/ttyUSB2'
##P3 t=636: set PPP serial to '/dev/ttyUSB2'
##P3 t=636: Serial::openDev('/dev/ttyUSB2') as FD 7 - Serial instance 0x818b5e0
##P2 t=636: GOOD: 'Device created successfully'
##P2 t=636: Using existing hardware config, not written to disk
##P3 t=636: Everything done - device created

##P3 t=636: HelperList::testAndRun(void)
##P3 t=636: HelperList::createHelperList()
##P3 t=636: INSIDE PARENT, uid=1000, pid=18784
##P3 t=636: HelperList::needsFixing
##P3 t=636: HelperList::~HelperList
##P3 t=636: ObserverManager COPY constructor
##P3 t=636: INSIDE PARENT, uid=1000, pid=18784
##P4 t=636: pppd version string 'pppd version 2.4.5' results in '2.4.5'.
##P4 t=636: DummyConnection::~DummyConnection(void)
##P4 t=636: ConnectionBaseClass::~ConnectionBaseClass(void)
##P3 t=636: ObserverManager destructor
##P2 t=636:

UIState::setState(1 -> 3)
##P4 t=636: SIMHandler::askForPIN() has been called
##P4 t=637: Query sends the following mesage: 'AT+CPIN?'
##P4 t=637: answer 1:'+CPIN: READY'
##P4 t=637: answer 2:'OK'
##P4 t=637: SIMHandler::isPINProtectionEnabled
##P4 t=637: Query sends the following mesage: 'AT+CLCK="SC",2'
##P4 t=637: answer 1:'OK'
##P2 t=637:

UIState::setState(3 -> 4)
##P2 t=638: ***UIState::update(void), state=4
##P4 t=638Serial::openDev-open("/dev/ttyUSB2") failed: Das Gerät oder die Ressource ist belegt
: ConnectionInfo::refreshCGREG(void)
##P4 t=638: Query sends the following mesage: 'AT+CGREG?'
##P4 t=639: answer 1:'OK'
##P4 t=639: ConnectionInfo::refreshCREG(void)
##P4 t=639: Query sends the following mesage: 'AT+CREG?'
##P4 t=639: answer 1:'+CREG: 0,1,55AE,7616'
##P4 t=639: answer 2:'OK'
##P4 t=639: ConnectionInfo::refreshSignalQuality(void)
##P4 t=639: Query sends the following mesage: 'AT+CSQ'
##P4 t=639: answer 1:'+CSQ: 8,99'
##P4 t=639: answer 2:'OK'
##P4 t=639: ConnectionInfo::refreshOperator(void)
##P4 t=639: Query sends the following mesage: 'AT+COPS?'
##P4 t=639: answer 1:'+COPS: 0,0,"o2 - de",2'
##P4 t=639: answer 2:'OK'
##P3 t=639: ConnectionInfo::refreshPPPStats
##P2 t=639:

UIState::setState(4 -> 5)
##P2 t=642: ***UIState::update(void), state=5
##P4 t=642: ConnectionInfo::refreshCGREG(void)
##P4 t=642: Query sends the following mesage: 'AT+CGREG?'
##P4 t=642: answer 1:'OK'
##P4 t=642: ConnectionInfo::refreshCREG(void)
##P4 t=642: Query sends the following mesage: 'AT+CREG?'
##P4 t=642: answer 1:'+CREG: 0,1,55AE,7616'
##P4 t=642: answer 2:'OK'
##P4 t=642: ConnectionInfo::refreshSignalQuality(void)
##P4 t=642: Query sends the following mesage: 'AT+CSQ'
##P4 t=642: answer 1:'+CSQ: 8,99'
##P4 t=642: answer 2:'OK'
##P4 t=642: ConnectionInfo::refreshOperator(void)
##P4 t=642: Query sends the following mesage: 'AT+COPS?'
##P4 t=642: answer 1:'+COPS: 0,0,"o2 - de",2'
##P4 t=642: answer 2:'OK'
##P3 t=642: ConnectionInfo::refreshPPPStats
##P3 t=644: umtsmonmain::ConnectPPP
##P2 t=644:

UIState::setState(5 -> 6)
##P2 t=644: Profile::Profile('')
##P2 t=644:   finally created profile for 'alice'
##P3 t=644: PPPConnection::startPPP entry
##P3 t=644: ConnectionBaseClass::setNewPPPState state 0 to 1
##P2 t=644: UIState::newConnectionState(1) callback called
##P2 t=644:

UIState::setState(6 -> 6)
##P4 t=644: ConnectionInfo:InhibitionCount ++, now is 1
##P3 t=644: TempSerialPort::TempSerialPort()
##P3 t=645: Serial::openDev('/dev/ttyUSB2') as FD 8 - Serial instance 0xbfe41624
##P3 t=645: ConnectionBaseClass::chat() start
##P4 t=645: Query sends the following mesage: 'AT&F'
##P4 t=645: answer 1:'OK'
##P4 t=645: Query sends the following mesage: 'ATE1'
##P4 t=645: answer 1:'OK'
##P4 t=645: Query sends the following mesage: 'AT+CGDCONT=1,"IP","internet.partner1"'
##P4 t=645: answer 1:'OK'
##P3 t=645: Dial String is: ATD*99***1#
##P4 t=645: Query sends the following mesage: 'ATD*99***1#'
##P4 t=645: answer 1:'CONNECT'
##P3 t=645: ConnectionBaseClass::chat() end with result: 1
##P4 t=645: Assembled PPP string is: 'idle 7200 asyncmap 0 updetach dump debug debug debug 460800 lock crtscts modem /dev/ttyUSB2 noipx novj nobsdcomp defaultroute usepeerdns user 123 password 123 '
##P4 t=645: ConnectionInfo:InhibitionCount ++, now is 2
##P2 t=645: PPPConnection::PPPThread::PPPThread()
##P2 t=645: PPPThread::run, before runCommand
##P3 t=645: INSIDE PARENT, uid=1000, pid=18784
##P2 t=649: PPPThread::run, after runCommand
##P3 t=650: TempSerialPort::~TempSerialPort()
##P3 t=650: SerialPort::closeDev() for FD 8
##P2 t=650: thePPPConnection.startConnection() returned without indicating problems
##P2 t=650: isDone is true
##P3 t=650: ConnectionBaseClass::setNewPPPState state 1 to 4
##P2 t=650: UIState::newConnectionState(4) callback called
##P2 t=650:

UIState::setState(6 -> 8)
##P2 t=651: ***UIState::update(void), state=8
##P3 t=651: ConnectionBaseClass::setNewPPPState state 4 to 0
##P2 t=651: UIState::newConnectionState(0) callback called
##P2 t=651:

UIState::setState(8 -> 5)
##P4 t=651: ConnectionInfo:InhibitionCount ++, now is 3
##P3 t=651: SerialPort::closeDev() for FD 7
##P4 t=652: ConnectionInfo:InhibitionCount -, now is 2
##P4 t=652: ConnectionInfo:InhibitionCount -, now is 1
##P3 t=652: ConnectionInfo probe inhibited
##P4 t=652: ConnectionInfo::refreshSignalQuality(void)
##P3 t=652: ConnectionInfo probe inhibited
##P3 t=652: ConnectionInfo probe inhibited
##P3 t=652: ConnectionInfo::refreshPPPStats
##P2 t=652: PPP State changed to present
##P3 t=652: MonthlyTraffic::start(anIsRoaming=0)
##P2 t=652: Profile::Profile('')
##P2 t=652:   finally created profile for 'alice'
##P2 t=654: ***UIState::update(void), state=5
##P3 t=654: ConnectionInfo probe inhibited
##P4 t=654: ConnectionInfo::refreshSignalQuality(void)
##P3 t=654: ConnectionInfo probe inhibited
##P3 t=654: ConnectionInfo probe inhibited
##P3 t=654: ConnectionInfo::refreshPPPStats
##P2 t=655: UIState::newConnectionState(0) callback called
##P2 t=655:

UIState::setState(5 -> 5)
##P3 t=655: thread end - wait and cleanup
##P2 t=655: ~PPPThread()
##P4 t=655: ConnectionInfo:InhibitionCount -, now is 0
##P2 t=655: ***UIState::update(void), state=5
##P4 t=655: ConnectionInfo::refreshCGREG(void)
##P4 t=655: Query sends the following mesage: 'AT+CGREG?'
##P2 t=655: unfortunately REGISTRATION_UNKNOWN as answer to AT+CGREG?
##P4 t=655: ConnectionInfo::refreshCREG(void)
##P4 t=655: Query sends the following mesage: 'AT+CREG?'
##P2 t=655: unfortunately REGISTRATION_UNKNOWN as answer to AT+CREG?
##P4 t=655: ConnectionInfo::refreshSignalQuality(void)
##P3 t=655: ConnectionInfo::refreshPPPStats
##P2 t=657: ***UIState::update(void), state=5
##P4 t=657: ConnectionInfo::refreshCGREG(void)
##P4 t=657: Query sends the following mesage: 'AT+CGREG?'
##P2 t=657: unfortunately REGISTRATION_UNKNOWN as answer to AT+CGREG?
##P4 t=657: ConnectionInfo::refreshCREG(void)
##P4 t=657: Query sends the following mesage: 'AT+CREG?'
##P2 t=657: unfortunately REGISTRATION_UNKNOWN as answer to AT+CREG?
##P4 t=657: ConnectionInfo::refreshSignalQuality(void)
##P3 t=657: ConnectionInfo::refreshPPPStats
##P2 t=660: ***UIState::update(void), state=5
##P4 t=660: ConnectionInfo::refreshCGREG(void)
##P4 t=660: Query sends the following mesage: 'AT+CGREG?'
##P2 t=660: unfortunately REGISTRATION_UNKNOWN as answer to AT+CGREG?
##P4 t=660: ConnectionInfo::refreshCREG(void)
##P4 t=660: Query sends the following mesage: 'AT+CREG?'
##P2 t=660: unfortunately REGISTRATION_UNKNOWN as answer to AT+CREG?
##P4 t=660: ConnectionInfo::refreshSignalQuality(void)
##P3 t=660: ConnectionInfo::refreshPPPStats
##P2 t=663: ***UIState::update(void), state=5
##P4 t=663: ConnectionInfo::refreshCGREG(void)
##P4 t=663: Query sends the following mesage: 'AT+CGREG?'
##P2 t=663: unfortunately REGISTRATION_UNKNOWN as answer to AT+CGREG?
##P4 t=663: ConnectionInfo::refreshCREG(void)
##P4 t=663: Query sends the following mesage: 'AT+CREG?'
##P2 t=663: unfortunately REGISTRATION_UNKNOWN as answer to AT+CREG?
##P4 t=663: ConnectionInfo::refreshSignalQuality(void)
##P3 t=663: ConnectionInfo::refreshPPPStats
##P3 t=663: LongSerialPort::~LongSerialPort()
##P3 t=663: SerialPort::closeDev() for FD -1

[Sebastian Koch]

After debugging the problem with the gdb for some hours I've found the problem in the method Runner::doesPPPDexist().
Here the author tries to extract the first C-Stiring from the file /proc/<pid>/cmdline by using the method ascii().
This fails when using LANG=de_DE@euro because the QTextStream::readLine() has already stripped the 0-bytes.
The myCmdLine will contain all arguments - even if .ascii() is used.
The umtsmon is linked to libqt-mt.so.3 => /usr/lib/libqt-mt.so.3 (0xb6f1f000).

From my point of view it is not a good idea to use the method QTextStream::readLine() via getFileFirstLine().
I suggest an explicit file helper function for this task.
Here is my patch:

Index: src/base/FileStuff.cpp

RCS file: /cvsroot/umtsmon/umtsmon/src/base/FileStuff.cpp,v
retrieving revision 1.3
diff -u -r1.3 FileStuff.cpp
-- src/base/FileStuff.cpp      25 Oct 2008 18:52:35 -0000      1.3
+++ src/base/FileStuff.cpp      24 May 2010 10:25:24 -0000
@@ -35,6 +35,23 @@
        return NULL;
}

+// helper method to extract the 1st c-string from a file with zero terminated
+// strings (e.g. /proc/<pid>/cmdline)
+QString
+FileStuff::getFileFirstCString(const QString& aFileName)
+{
+       QFile myFile(aFileName);
+       if (myFile.open(IO_ReadOnly))
+       {
+               QTextStream in(&myFile);
+               QString myLine = in.read();
+               QString myCString = myLine.ascii();
+               myFile.close();
+               return myCString;
+       }
+       return NULL;
+}
+
bool
FileStuff::doesFileContainString(
        const QString& aFileName,
Index: src/base/FileStuff.h
===================================================================
RCS file: /cvsroot/umtsmon/umtsmon/src/base/FileStuff.h,v
retrieving revision 1.3
diff -u -r1.3 FileStuff.h
-- src/base/FileStuff.h        25 Oct 2008 18:52:35 -0000      1.3
+++ src/base/FileStuff.h        24 May 2010 10:25:24 -0000
@@ -41,6 +41,7 @@
         *               a QString with the first line (max 255 chars) otherwise
        */
        static QString getFileFirstLine(const QString& aFileName);
+       static QString getFileFirstCString(const QString& aFileName);

        /** checks if the file is readable and/or writable by the user
         *  @returns the corresponding value out of the enum ReadWrite. If file doesn't exist, returns NOTHING
Index: src/base/Runner.cpp
===================================================================
RCS file: /cvsroot/umtsmon/umtsmon/src/base/Runner.cpp,v
retrieving revision 1.13
diff -u -r1.13 Runner.cpp
-- src/base/Runner.cpp 26 Apr 2009 22:25:43 -0000      1.13
+++ src/base/Runner.cpp 24 May 2010 10:25:24 -0000
@@ -226,9 +226,14 @@
        {
                QString myDirName = myFileInfo->fileName();

+#if 0
                // be warned: if you don't use the .ascii()
                // myCmdLine will contain all arguments as well, separated by \0…
                QString myCmdLine = FileStuff::getFileFirstLine("/proc/"+myDirName+"/cmdline").ascii();
+#else
+               // seb, 2010/05/23, use an explicit heler method to extract te first zero terminated string
+               QString myCmdLine = FileStuff::getFileFirstCString("/proc/"+myDirName+"/cmdline");
+#endif
                if (myCmdLine == myPPPDPath || myCmdLine == "pppd")
                        return myDirName.toLong(NULL, 10);
        }

I hope this will help…
Regards,
Sebastian