GHI.Networking.PPPSerialModem+ConnectionFailedException

Hello,

I’m seeing this error when using the PPPSerialModem class.

[quote] #### Exception GHI.Networking.PPPSerialModem+ConnectionFailedException - 0x00000000 (7) ####
#### Message:
#### GHI.Networking.PPPSerialModem::Connect [IP: 00a6] ####
#### GHI.Networking.PPPSerialModem::Connect [IP: 000b] ####[/quote]
I see this error in 2 scenarios:

[ol]Connect the modem and just leave the connection open. At some point the cellular network will terminate the connection. After this happens calling the connect method will never be successful again until the board is rebooted. I’m guessing the cause is that the PPPSerialModem class is not properly handling a termination initiated by the cellular network and something in the state is not reset correctly.
A connection is established, the network is used, and then the modem is disconnected. The error starts to occur in this scenario as well. In this scenario of quick short uses of the PPPSerialModem the class seems to survive much longer, but eventually it will start to fail with the same exception.[/ol]

It seems like something in PPPSerialModem isn’t tracking the state of the interface properly when disconnecting and something is getting left open or not getting re-initialized properly.

In both scenarios when the modem disconnects I do get the NetworkChange_NetworkAddressChanged event which shows the IP address is reset to 0.0.0.0 and I also get the NetworkChange_NetworkAvailabilityChanged event which shows the interface is not available. However, these events get raised twice. Once immediately after calling PPPSerialModem.Disconnect() (or after the cellular network forces the disconnect), then again 15 seconds to a minute later.

I have not found a way to recover after the GHI.Networking.PPPSerialModem+ConnectionFailedException in any scenario. The only solution I can find is to reboot the board. Does anyone know if there a way to recover after this exception?

Thanks.

@ PhilH - Are you using our cellular radio module? Can you post a minimal example?

FEZ Spider - NETMF SDK 2015 Pre-Release 2
Modem is a Multiconnect Cell 100 MTC-EV3-B01

Here are two samples one for either scenario.

Scenario 1 connects the modem and just queries for google’s DNS entry every 2 minutes to simulate network traffic. At some point the cellular network will force the connection to terminate. After this happens the code will attempt to reconnect but it will never be successful. Each reconnect attempt fails with a GHI.Networking.PPPSerialModem+ConnectionFailedException. This one seems like the class isn’t gracefully handling the PPP terminate request when it comes from the cellular network side of the connection.

[quote]Program Started
Sending Command: ATD#777
Modem Response: CONNECT
Network Address Changed: 75.227.116.163
Network Available: True
The thread ‘’ (0x3) has exited with code 0 (0x0).
Thread Start
Getting Host Entry for google.com
Host Entry: 63.84.3.22
Thread End
The thread ‘’ (0x6) has exited with code 0 (0x0).
Thread Start
Getting Host Entry for google.com
Host Entry: 63.84.3.22
Thread End
The thread ‘’ (0x7) has exited with code 0 (0x0).[/quote]


using Gadgeteer.Networking;
using GHI.Networking;
using Microsoft.SPOT;
using Microsoft.SPOT.Hardware;
using Microsoft.SPOT.Net.NetworkInformation;
using Microsoft.SPOT.Presentation;
using Microsoft.SPOT.Presentation.Controls;
using Microsoft.SPOT.Presentation.Media;
using Microsoft.SPOT.Presentation.Shapes;
using Microsoft.SPOT.Touch;
using System;
using System.Collections;
using System.IO;
using System.IO.Ports;
using System.Net;
using System.Text;
using System.Threading;
using GT = Gadgeteer;
using GTM = Gadgeteer.Modules;

namespace ModemTest
{
    public partial class Program
    {
        private SerialPort port;
        private PPPSerialModem modem;
        private GT.Timer timer;
        private bool connected = false;

        private void ProgramStarted()
        {
            Debug.Print("Program Started");

            NetworkChange.NetworkAddressChanged += (x, y) => { Debug.Print("Network Address Changed: " + Microsoft.SPOT.Net.NetworkInformation.NetworkInterface.GetAllNetworkInterfaces()[3].IPAddress); };
            NetworkChange.NetworkAvailabilityChanged += (x, y) => 
            { 
                Debug.Print("Network Available: " + y.IsAvailable);
                connected = y.IsAvailable;
            };

            timer = new GT.Timer(120000); // 2 minutes
            timer.Tick += timer_Tick;

            string serialPortName = GT.Socket.GetSocket(4, false, null, "").SerialPortName;
            port = new SerialPort(serialPortName, 115200, Parity.None, 8, StopBits.One);
            port.Handshake = Handshake.RequestToSend;
            port.ReadTimeout = 100;
            port.Open();
            port.DiscardInBuffer();
            port.DiscardOutBuffer();

            modem = new PPPSerialModem(port);

            Connect();
            
            timer.Start();
        }

        void timer_Tick(GT.Timer timer)
        {
            if (connected)
            {
                new Thread(Work).Start();
            }
            else
            {
                //Modem disconnected.
                if (modem.LinkConnected)
                {
                    modem.Disconnect();
                }

                //Reset the modem.
                SendATCommand("+++", 5000);
                SendATCommand("ATH", 3000);
                SendATCommand("+++", 5000);

                //Reconnect
                Connect();
            }
        }
            
        void Connect()
        {
            SendATCommand("ATD#777", 40000);

            try
            {
                if (!modem.Opened)
                    modem.Open();

                modem.Connect(PPPSerialModem.AuthenticationType.Pap, "", "");

                Thread.Sleep(5000);
            }
            catch (Exception ex)
            {
                Debug.Print(ex.ToString());
            }

            connected = modem.LinkConnected;
        }

        private void Work()
        {
            Debug.Print("Thread Start");

            HTTPRequest();

            Debug.Print("Thread End");
        }

        private ModemCommandStatus SendATCommand(string command, int maxWaitTime)
        {
            Debug.Print("Sending Command: " + command);

            if (command != "+++")
                command += "\r";

            WriteToModem(command);

            DateTime cmdExpiration = DateTime.Now.AddMilliseconds(maxWaitTime);
            ModemCommandStatus modemResponse = ModemCommandStatus.Unknown;
            byte[] readBuffer = new byte[0];
            while (DateTime.Now < cmdExpiration)
            {
                Thread.Sleep(0);

                if (port.BytesToRead > 0)
                {
                    byte[] modemBuffer = new byte[port.BytesToRead];
                    int bytesRead = port.Read(modemBuffer, 0, modemBuffer.Length);
                    byte[] tempBuffer = new byte[readBuffer.Length];
                    Array.Copy(readBuffer, tempBuffer, readBuffer.Length);
                    readBuffer = new byte[tempBuffer.Length + modemBuffer.Length];
                    Array.Copy(tempBuffer, readBuffer, tempBuffer.Length);
                    Array.Copy(modemBuffer, 0, readBuffer, tempBuffer.Length, modemBuffer.Length);

                    modemResponse = GetResponse(ref readBuffer);
                    if (modemResponse != ModemCommandStatus.Unknown)
                        break;
                }
            }

            Thread.Sleep(20);

            string responseText = "UNKNOWN";
            switch (modemResponse)
            {
                case ModemCommandStatus.Success:
                    responseText = "OK";
                    break;
                case ModemCommandStatus.Connect:
                    responseText = "CONNECT";
                    break;
                case ModemCommandStatus.NoCarrier:
                    responseText = "NO CARRIER";
                    break;
                case ModemCommandStatus.Error:
                    responseText = "ERROR";
                    break;

            }

            Debug.Print("Modem Response: " + responseText);

            return modemResponse;
        }

        private ModemCommandStatus GetResponse(ref byte[] data)
        {
            ModemCommandStatus status = ModemCommandStatus.Unknown;

            if (FindMatch(data, new byte[] { 13, 10, 79, 75, 13, 10 }) > -1) //\r\nOK\r\n
            {
                status = ModemCommandStatus.Success;
            }
            else if (FindMatch(data, new byte[] { 13, 10, 69, 82, 82, 79, 82, 13, 10 }) > -1) //\r\nERROR\r\n
            {
                status = ModemCommandStatus.Error;
            }
            else if (FindMatch(data, new byte[] { 13, 10, 67, 79, 78, 78, 69, 67, 84 }) > -1) //\r\nCONNECT
            {
                status = ModemCommandStatus.Connect;
            }
            else if (FindMatch(data, new byte[] { 13, 10, 78, 79, 32, 67, 65, 82, 82, 73, 69, 82, 13, 10 }) > -1) //\r\nNO CARRIER\r\n
            {
                status = ModemCommandStatus.NoCarrier;
            }

            return status;
        }

        public int FindMatch(byte[] buffer, byte[] pattern)
        {
            if (buffer != null && pattern != null && buffer.Length != 0 && pattern.Length != 0 && pattern.Length <= buffer.Length)
            {
                int resumeIndex;
                for (int i = 0; i <= buffer.Length - pattern.Length; i++)
                {
                    if (buffer[i] == pattern[0])
                    {
                        resumeIndex = 0;
                        for (int x = 1; x < pattern.Length; x++)
                        {
                            if (buffer[i + x] == pattern[x])
                            {
                                if (x == pattern.Length - 1)
                                    return i;
                                else if (resumeIndex == 0 && buffer[i + x] == pattern[0])
                                    resumeIndex = i + x;
                            }
                            else
                            {
                                if (resumeIndex > 0)
                                    i = resumeIndex - 1;
                                else if (x > 1)
                                    i += (x - 1);
                                break;
                            }
                        }
                    }
                }
            }
            return -1;
        }

        public enum ModemCommandStatus
        {
            Success,
            Connect,
            NoCarrier,
            Error,
            Unknown
        }

        private void WriteToModem(string command)
        {
            var sendBuffer = Encoding.UTF8.GetBytes(command);
            port.Write(sendBuffer, 0, sendBuffer.Length);
        }

        private void HTTPRequest()
        {
            try
            {
                Debug.Print("Getting Host Entry for google.com...");
                var dnsEntry = Dns.GetHostEntry("google.com");
                Debug.Print(string.Concat("Host Entry: ", dnsEntry.AddressList[0].ToString()));
            }
            catch (Exception ex)
            {
                Debug.Print(string.Concat("Dns.GetHostEntry() Error: ", ex.ToString()));
            }
        }
    }
}

Scenario 2 connects the modem, queries for google’s DNS entry and then disconnects the modem every 2 minutes. This will work fine for several hours and many many times over. But at some point the connect method will start to fail with a GHI.Networking.PPPSerialModem+ConnectFailedException. Once that happens the only solution is to reboot the board.

[quote]Program Started
Thread Start
Sending Command: ATD#777
Modem Response: CONNECT
Network Address Changed: 75.236.70.254
Network Available: True
Getting Host Entry for google.com
Host Entry: 216.58.216.206
Sending Command: +++
Network Address Changed: 0.0.0.0
Network Available: False
Modem Response: NO CARRIER
Sending Command: ATH
Modem Response: OK
Sending Command: +++
Modem Response: UNKNOWN
Thread End
The thread ‘’ (0x5) has exited with code 0 (0x0).
Network Address Changed: 0.0.0.0
Network Available: False[/quote]


using Gadgeteer.Networking;
using GHI.Networking;
using Microsoft.SPOT;
using Microsoft.SPOT.Hardware;
using Microsoft.SPOT.Net.NetworkInformation;
using Microsoft.SPOT.Presentation;
using Microsoft.SPOT.Presentation.Controls;
using Microsoft.SPOT.Presentation.Media;
using Microsoft.SPOT.Presentation.Shapes;
using Microsoft.SPOT.Touch;
using System;
using System.Collections;
using System.IO;
using System.IO.Ports;
using System.Net;
using System.Text;
using System.Threading;
using GT = Gadgeteer;
using GTM = Gadgeteer.Modules;

namespace ModemTest
{
    public partial class Program
    {
        private SerialPort port;
        private PPPSerialModem modem;
        private GT.Timer timer;

        private void ProgramStarted()
        {
            Debug.Print("Program Started");

            NetworkChange.NetworkAvailabilityChanged += (x, y) => { Debug.Print("Network Available: " + y.IsAvailable); };
            NetworkChange.NetworkAddressChanged += (x, y) => { Debug.Print("Network Address Changed: " + Microsoft.SPOT.Net.NetworkInformation.NetworkInterface.GetAllNetworkInterfaces()[3].IPAddress); };

            timer = new GT.Timer(120000); // 2 minutes
            timer.Tick += timer_Tick;

            string serialPortName = GT.Socket.GetSocket(4, false, null, "").SerialPortName;
            port = new SerialPort(serialPortName, 115200, Parity.None, 8, StopBits.One);
            port.Handshake = Handshake.RequestToSend;
            port.ReadTimeout = 100;
            port.Open();
            port.DiscardInBuffer();
            port.DiscardOutBuffer();

            modem = new PPPSerialModem(port);
            timer.Start();
        }

        void timer_Tick(GT.Timer timer)
        {
            new Thread(Work).Start();
        }
                
        private void Work()
        {
            Debug.Print("Thread Start");

            SendATCommand("ATD#777", 40000);

            try
            {
                if (!modem.Opened)
                    modem.Open();

                modem.Connect(PPPSerialModem.AuthenticationType.Pap, "", "");

                Thread.Sleep(5000);

                if (modem.LinkConnected)
                {
                    HTTPRequest();

                    Thread.Sleep(60000); //Sleep for 1 minute.

                    modem.Disconnect();
                    modem.Close();
                }
            }
            catch (Exception ex)
            {
                Debug.Print(ex.ToString());
            }

            SendATCommand("+++", 5000);
            SendATCommand("ATH", 3000);
            SendATCommand("+++", 5000);

            Debug.Print("Thread End");
        }

        private ModemCommandStatus SendATCommand(string command, int maxWaitTime)
        {
            Debug.Print("Sending Command: " + command);

            if (command != "+++")
                command += "\r";

            WriteToModem(command);

            DateTime cmdExpiration = DateTime.Now.AddMilliseconds(maxWaitTime);
            ModemCommandStatus modemResponse = ModemCommandStatus.Unknown;
            byte[] readBuffer = new byte[0];
            while (DateTime.Now < cmdExpiration)
            {
                Thread.Sleep(0);

                if (port.BytesToRead > 0)
                {
                    byte[] modemBuffer = new byte[port.BytesToRead];
                    int bytesRead = port.Read(modemBuffer, 0, modemBuffer.Length);
                    byte[] tempBuffer = new byte[readBuffer.Length];
                    Array.Copy(readBuffer, tempBuffer, readBuffer.Length);
                    readBuffer = new byte[tempBuffer.Length + modemBuffer.Length];
                    Array.Copy(tempBuffer, readBuffer, tempBuffer.Length);
                    Array.Copy(modemBuffer, 0, readBuffer, tempBuffer.Length, modemBuffer.Length);

                    modemResponse = GetResponse(ref readBuffer);
                    if (modemResponse != ModemCommandStatus.Unknown)
                        break;
                }
            }

            Thread.Sleep(20);

            string responseText = "UNKNOWN";
            switch (modemResponse)
            {
                case ModemCommandStatus.Success:
                    responseText = "OK";
                    break;
                case ModemCommandStatus.Connect:
                    responseText = "CONNECT";
                    break;
                case ModemCommandStatus.NoCarrier:
                    responseText = "NO CARRIER";
                    break;
                case ModemCommandStatus.Error:
                    responseText = "ERROR";
                    break;

            }

            Debug.Print("Modem Response: " + responseText);

            return modemResponse;
        }

        private ModemCommandStatus GetResponse(ref byte[] data)
        {
            ModemCommandStatus status = ModemCommandStatus.Unknown;

            if (FindMatch(data, new byte[] { 13, 10, 79, 75, 13, 10 }) > -1) //\r\nOK\r\n
            {
                status = ModemCommandStatus.Success;
            }
            else if (FindMatch(data, new byte[] { 13, 10, 69, 82, 82, 79, 82, 13, 10 }) > -1) //\r\nERROR\r\n
            {
                status = ModemCommandStatus.Error;
            }
            else if (FindMatch(data, new byte[] { 13, 10, 67, 79, 78, 78, 69, 67, 84 }) > -1) //\r\nCONNECT
            {
                status = ModemCommandStatus.Connect;
            }
            else if (FindMatch(data, new byte[] { 13, 10, 78, 79, 32, 67, 65, 82, 82, 73, 69, 82, 13, 10 }) > -1) //\r\nNO CARRIER\r\n
            {
                status = ModemCommandStatus.NoCarrier;
            }

            return status;
        }

        public int FindMatch(byte[] buffer, byte[] pattern)
        {
            if (buffer != null && pattern != null && buffer.Length != 0 && pattern.Length != 0 && pattern.Length <= buffer.Length)
            {
                int resumeIndex;
                for (int i = 0; i <= buffer.Length - pattern.Length; i++)
                {
                    if (buffer[i] == pattern[0])
                    {
                        resumeIndex = 0;
                        for (int x = 1; x < pattern.Length; x++)
                        {
                            if (buffer[i + x] == pattern[x])
                            {
                                if (x == pattern.Length - 1)
                                    return i;
                                else if (resumeIndex == 0 && buffer[i + x] == pattern[0])
                                    resumeIndex = i + x;
                            }
                            else
                            {
                                if (resumeIndex > 0)
                                    i = resumeIndex - 1;
                                else if (x > 1)
                                    i += (x - 1);
                                break;
                            }
                        }
                    }
                }
            }
            return -1;
        }

        public enum ModemCommandStatus
        {
            Success,
            Connect,
            NoCarrier,
            Error,
            Unknown
        }

        private void WriteToModem(string command)
        {
            var sendBuffer = Encoding.UTF8.GetBytes(command);
            port.Write(sendBuffer, 0, sendBuffer.Length);
        }

        private void HTTPRequest()
        {
            try
            {
                Debug.Print("Getting Host Entry for google.com...");
                var dnsEntry = Dns.GetHostEntry("google.com");
                Debug.Print(string.Concat("Host Entry: ", dnsEntry.AddressList[0].ToString()));
            }
            catch (Exception ex)
            {
                Debug.Print(string.Concat("Dns.GetHostEntry() Error: ", ex.ToString()));
            }
        }
    }
}

@ PhilH - Thanks for the write up. Does the modem force a disconnection by sending NO CARRIER?


                modem.Connect(PPPSerialModem.AuthenticationType.Pap, "", "");

                Thread.Sleep(5000);

                if (modem.LinkConnected)
                {
                    HTTPRequest();

                    Thread.Sleep(60000); //Sleep for 1 minute.

                    modem.Disconnect();
                    modem.Close();
                }
            }
            catch (Exception ex)
            {
                Debug.Print(ex.ToString());
            }

            SendATCommand("+++", 5000);
            SendATCommand("ATH", 3000);
            SendATCommand("+++", 5000);

The “NO CARRIER” is actually the response to the “ATH” (hang up) command. The cellular disconnect is accomplished by the call to modem.Disconnect(); and to modem.Close(); (As a side note I’ve tried it both with and without the Close() after the Disconnect(). I don’t see a difference either way.)

The 3 AT commands I send after the disconnect (+++, ATH, +++) are just insurance that the modem state is reset to its “hang up” state. This way it will be ready for the dial command “ATD#777” the next time I want to establish a connection.

@ PhilH - What causes the modem to initiate the disconnect in the first place? How do you receive notification that it was disconnected? The failure of a request?

In scenario 1 where the cellular network forces a disconnect I get notification from the NetworkChange.NetworkAvailabilityChanged event.

In scenario 2 I’m just using the modem when I know I need to perform a network operation. Which is usually just sending a small amount of data to a webservice. After the information has been sent and I no longer need the connection I close it by calling .Disconnect() on the PPPSerialModem class to disconnect the modem.

@ PhillH, I have something slightly different with the PPP driver and wonder if you have something similar. After I setup the modem to dial it comes back with CONNECT and then I pass this serial port to the PPP driver and call it’s connect function. In my case the modem never connects and monitoring the serial line I can see a NO CARRIER appear after some PPP negotiations have been carried out.

At this point the connect function returns and now I cannot access the modem via any serial commands. I’ve tried sending +++ to it but I still don’t get any responses back from the modem. I can see by monitoring the serial line that the modem sends a reply but NETMF always shows that serialport byte count as zero. My only fix is to reboot the device.

The only exception I get is when connect fails.

Have you come across this issue at all?

In the 2014 R5 SDK I had a similar issue. The PPP driver would only work correctly when running the application with the visual studio debugger attached. If I ran the code without the visual studio debugger attached the PPP driver would not send anything on the serial line at all. If I ran the code with the visual studio debugger attached the PPP would work correctly and the modem would connect.

GHI resolved the bug in 2015 R1 pre-release 2 for me. Its funny because I can’t find it in the release notes online, but its in the release notes included with the SDK package I downloaded at the time.

[quote]2015 R1 Pre-Release 2
Built 2015-06-01
Requires NETMF SDK 4.3 QFE2

EMX

Version

  • 4.3.7.8 Firmware
  • 4.3.7.7 Loader

Changes

  • Fixed PPP not working when not debugging.[/quote]
    If you go back to an older SDK does the PPP driver work on your device?

A few additional items worth noting:

My modem will not respond to a “+++” command. After the “ATD#777” command the modem switches context from command mode to data mode where it is ready to accept the PPP connection. The “+++” is an escape command which takes the modem from its data context to command mode. At which point the modem will respond to any commands issued. After you issue the “+++” wait a second or two and then give it a command that it should respond to like “ATH”. It should respond with something at that point.

Secondly when I was playing with my modem initially I discovered the PPP connection will not work unless handshaking is enabled on the serial line. You may want to check that your handshaking is configured properly.

Thanks PhillH, I have not rolled back the library yet to try. I may install he older library on the laptop to try it out.

As for the +++, I have a 1 second guard time on either side as per the specifications for its use. The modem responds as I can see the replies with the sniffer I have on the line. The issue is that there is nothing received or at least that the seriaport does not report any characters in the buffer but I can clearly see that something is entering the serial port and it is open. It’s as if something in the PPP driver was still handling the received data and taking it before my code can see it.

@ Dave McLaughlin - It certainly sounds like the PPP class is holding a reference to your serial port. You could try to free up the serial port by setting your references to the PPP class null and calling the garbage collector. Or if that doesn’t work what happens if you .Dispose() the PPP class?

Disposing of either or both does not work. I tried to dispose of the serialport and then recreate it. I still don’t get any received data in the buffer even though I can see if on the sniffer. Transmit is OK as I can see the reply via the said sniffer. It’s just that receive seems to get messed up somewhere.

After running a test over night I think I am also seeing the same issue you’re seeing. But in my case the issue doesn’t begin until I’ve made several successful connection and disconnections. I think in my case its taking much longer for the issue to occur than in your case.

I set up a test yesterday and let it run over night. The modem would connect every 4 minutes, perform a simple network operation and then disconnect. This ran successfully for 15 hours. Then I think I saw the issue you’re describing.

After 15 hours of connects and disconnects every 4 minutes the code called the PPPSerialModem.Connect() method but this time the method never connected, and I did not receive the PPPSerialModem+ConnectionFailedException. In fact I don’t know what happened but I assume the thread aborted with an Exception that my try catch did not catch. I have a try catch around the whole process which just logs the exception, but I didn’t get anything in my log. Then 4 minutes later in my log file I see the code attempting to issue AT commands to the modem to get it ready for another connection except this time there are no responses from the modem at all to any of the AT the commands issued. After that the code attempted to call PPPSerialModem.Connect and this time it caught a PPPSerialModem+ConnectionFailedException. I think the issue you’re describing is somehow related to the problem I’m seeing.

@ PhilH - You were correct in that the driver was holding onto the serial port. There were some conditions (usually remote disconnection), where the driver would not shutdown the internal serial reader, so any data that was received would be read by it before it could be passed up to the managed application until the board was reset. This has been fixed for the next pre-release.

@ John - Great news. Thanks for the quick turn around on this one.

@ PhilH - Happy to help

Any news on when the next release will be John?

I’ve been asked for a working unit for testing and have indicated about 4-6 weeks for one. :frowning:

@ Dave McLaughlin - As long as nothing comes up, it should be soon.