Learn how easy it is to sync an existing GitHub or Google Code repo to a SourceForge project! See Demo

Close

Sierra Wireless in Lenovo X61, pppd escaped

2010-05-24
2013-04-15
  • Sebastian Koch
    Sebastian Koch
    2010-05-24

    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
    Sebastian Koch
    2010-05-24

    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