3G won't start on boot

[Damian Christie]

…but will start manually. I’ve gotten around this by calling “/usr/sbin/pppd call gsm” in a script run after boot has completed. I’ve compared the ppp configuration to another mLinux box that works correctly and can see no difference. I can see in “/var/log/messages” that after the “ATD*99***1#” command is sent (as below) I get a “NO CARRIER” message. Again, running this manually with the same settings results in a successful connection. Is there anything else I could check??

Mar 29 13:35:25 mtcdt local2.info chat[454]: send (ATD*99***1#^M)
Mar 29 13:35:25 mtcdt local2.info chat[454]: timeout set to 120 seconds
Mar 29 13:35:25 mtcdt local2.info chat[454]: expect (CONNECT)
Mar 29 13:35:25 mtcdt local2.info chat[454]: ^M
Mar 29 13:35:25 mtcdt local2.info chat[454]: ATD*99***1#^M^M
Mar 29 13:35:25 mtcdt local2.info chat[454]: NO CARRIER
Mar 29 13:35:25 mtcdt local2.info chat[454]: -- failed
Mar 29 13:35:25 mtcdt local2.info chat[454]: Failed (NO CARRIER)

• This topic was modified 7 years, 1 month ago by Damian Christie.

[Jeff Hatch]

Damian,

The only thing that I can think of without more information is that the radio on that device is “coming up” slower than on the other device for some reason. I’m assuming that both the device that works and the device with the problem are using the same provider and are effectively in the same location and behave the same with the exact same SIM card?

Jeff

[Damian Christie]

Same provider, same location. I haven’t tried with the same SIM, since it’s kind of difficult to get the SIM in and out. Is there any way I can verify it’s waiting for the 120s timeout with an echo somewhere? It seems to give up very quickly.

Thanks.

[Jeff Hatch]

Damian,

Can you post the entire output of the chat script? That might give a better clue. As it is it appears that the radio is responding to the chat script, but failing on connection establishment. It is difficult to get any debugging from the radio itself. It might be possible to turn up the debugging coming out of ppp though.

Jeff

[Damian Christie]

You mean the gsm_chat script?

root@mtcdt:~# cat /etc/ppp/peers/gsm_chat
SAY "GSM chat\n"
ECHO OFF
ABORT 'NO DIAL TONE'
ABORT 'NO DIALTONE'
ABORT 'NO ANSWER'
ABORT 'NO CARRIER'
ABORT 'DELAYED'
ABORT 'VOICE'
ABORT 'BUSY'
'' 'AT'
OK 'ATZ'
OK 'AT+CSQ'
# ----------------------------------
# Set the APN for your provider here
# ----------------------------------
#OK 'AT+CGDCONT=1,"IP","proxy"'
#OK 'AT+CGDCONT=1,"IP","ISP.CINGULAR"'
#OK 'AT+CGDCONT=1,"IP","internet2.voicestream.com"'
OK 'AT+CGDCONT=1,"IP","hs.vodafone.ie"'
SAY "Dialing...\n"
#OK 'ATD*99#'
OK 'ATD*99***1#'
SAY "Waiting for CONNECT...\n"
TIMEOUT 120
CONNECT ''
SAY "Connected\n"
root@mtcdt:~#


Below is the full output of /var/log/messages after startup.


root@mtcdt:~# cat /var/log/messages
Mar 30 14:55:38 mtcdt syslog.info syslogd started: BusyBox v1.22.1
Mar 30 14:55:38 mtcdt user.notice kernel: klogd started: BusyBox v1.22.1 (2016-05-05 19:12:23 CDT)
Mar 30 14:55:38 mtcdt user.info kernel: sam9x5: read 512 bytes from id eeprom
Mar 30 14:55:38 mtcdt user.info kernel: at24_get_setup: found a match for eeprom at 50
Mar 30 14:55:38 mtcdt user.info kernel: at24 1-0050: 512 byte 24c04 EEPROM, writable, 16 bytes/write
Mar 30 14:55:38 mtcdt user.info kernel: sam9x5: read 512 bytes from ap1 eeprom
Mar 30 14:55:38 mtcdt user.info kernel: at24_get_setup: found a match for eeprom at 52
Mar 30 14:55:38 mtcdt user.info kernel: at24 1-0052: 512 byte 24c04 EEPROM, writable, 16 bytes/write
Mar 30 14:55:38 mtcdt user.info kernel: sam9x5: ap2 eeprom read failed: -110
Mar 30 14:55:38 mtcdt user.info kernel: atmel_nand 40000000.nand: Using dma0chan0 for DMA transfers.
Mar 30 14:55:38 mtcdt user.info kernel: ONFI param page 0 valid
Mar 30 14:55:38 mtcdt user.info kernel: ONFI flash detected
Mar 30 14:55:38 mtcdt user.info kernel: NAND device: Manufacturer ID: 0x2c, Chip ID: 0xaa (Micron MT29F2G08ABBEAHC), 256MiB, page size: 2048, OOB size: 64
Mar 30 14:55:38 mtcdt user.info kernel: atmel_nand 40000000.nand: ONFI params, minimum required ECC: 4 bits in 512 bytes
Mar 30 14:55:38 mtcdt user.info kernel: atmel_nand 40000000.nand: Initialize PMECC params, cap: 4, sector: 512
Mar 30 14:55:38 mtcdt user.info kernel: Scanning device for bad blocks
Mar 30 14:55:38 mtcdt user.notice kernel: 9 ofpart partitions found on MTD device atmel_nand
Mar 30 14:55:38 mtcdt user.notice kernel: Creating 9 MTD partitions on "atmel_nand":
Mar 30 14:55:38 mtcdt user.notice kernel: 0x000000000000-0x000010000000 : "NANDFlash"
Mar 30 14:55:38 mtcdt user.notice kernel: 0x000000000000-0x000000040000 : "at91bootstrap"
Mar 30 14:55:38 mtcdt user.notice kernel: 0x000000040000-0x0000000c0000 : "u-Boot"
Mar 30 14:55:38 mtcdt user.notice kernel: 0x0000000c0000-0x000000160000 : "u-Boot Config"
Mar 30 14:55:38 mtcdt user.notice kernel: 0x000000160000-0x000000200000 : "u-Boot Redundant Config"
Mar 30 14:55:38 mtcdt user.notice kernel: 0x000000200000-0x000000800000 : "uImage"
Mar 30 14:55:38 mtcdt user.notice kernel: 0x000000800000-0x000001000000 : "Config"
Mar 30 14:55:38 mtcdt user.notice kernel: 0x000001000000-0x000001800000 : "OEM Config"
Mar 30 14:55:38 mtcdt user.notice kernel: 0x000001800000-0x000010000000 : "Rootfs"
Mar 30 14:55:38 mtcdt user.info kernel: libphy: MACB_mii_bus: probed
Mar 30 14:55:38 mtcdt user.info kernel: macb f802c000.ethernet eth0: Cadence MACB at 0xf802c000 irq 23 (00:08:00:4a:02:db)
Mar 30 14:55:38 mtcdt user.info kernel: macb f802c000.ethernet eth0: attached PHY driver [Generic PHY] (mii_bus:phy_addr=f802c000.etherne:00, irq=-1)
Mar 30 14:55:38 mtcdt user.info kernel: PPP generic driver version 2.4.2
Mar 30 14:55:38 mtcdt user.info kernel: PPP BSD Compression module registered
Mar 30 14:55:38 mtcdt user.info kernel: PPP Deflate Compression module registered
Mar 30 14:55:38 mtcdt user.info kernel: ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
Mar 30 14:55:38 mtcdt user.info kernel: ehci-atmel: EHCI Atmel driver
Mar 30 14:55:38 mtcdt user.info kernel: atmel-ehci 700000.ehci: EHCI Host Controller
Mar 30 14:55:38 mtcdt user.info kernel: atmel-ehci 700000.ehci: new USB bus registered, assigned bus number 1
Mar 30 14:55:38 mtcdt user.info kernel: atmel-ehci 700000.ehci: irq 31, io mem 0x00700000
Mar 30 14:55:38 mtcdt user.info kernel: atmel-ehci 700000.ehci: USB 2.0 started, EHCI 1.00
Mar 30 14:55:38 mtcdt user.info kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
Mar 30 14:55:38 mtcdt user.info kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Mar 30 14:55:38 mtcdt user.info kernel: usb usb1: Product: EHCI Host Controller
Mar 30 14:55:38 mtcdt user.info kernel: usb usb1: Manufacturer: Linux 3.12.27 ehci_hcd
Mar 30 14:55:38 mtcdt user.info kernel: usb usb1: SerialNumber: 700000.ehci
Mar 30 14:55:38 mtcdt user.info kernel: hub 1-0:1.0: USB hub found
Mar 30 14:55:38 mtcdt user.info kernel: hub 1-0:1.0: 3 ports detected
Mar 30 14:55:38 mtcdt user.info kernel: ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
Mar 30 14:55:38 mtcdt user.info kernel: at91_ohci 600000.ohci: AT91 OHCI
Mar 30 14:55:38 mtcdt user.info kernel: at91_ohci 600000.ohci: new USB bus registered, assigned bus number 2
Mar 30 14:55:38 mtcdt user.info kernel: at91_ohci 600000.ohci: irq 31, io mem 0x00600000
Mar 30 14:55:38 mtcdt user.info kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0001
Mar 30 14:55:38 mtcdt user.info kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Mar 30 14:55:38 mtcdt user.info kernel: usb usb2: Product: AT91 OHCI
Mar 30 14:55:38 mtcdt user.info kernel: usb usb2: Manufacturer: Linux 3.12.27 ohci_hcd
Mar 30 14:55:38 mtcdt user.info kernel: usb usb2: SerialNumber: at91
Mar 30 14:55:38 mtcdt user.info kernel: hub 2-0:1.0: USB hub found
Mar 30 14:55:38 mtcdt user.info kernel: hub 2-0:1.0: 3 ports detected
Mar 30 14:55:38 mtcdt user.warn kernel: rtc (null): invalid alarm value: 1900-1-1 0:0:0
Mar 30 14:55:38 mtcdt user.info kernel: at91_rtc fffffeb0.rtc: rtc core: registered fffffeb0.rtc as rtc0
Mar 30 14:55:38 mtcdt user.info kernel: at91_rtc fffffeb0.rtc: AT91 Real Time Clock driver.
Mar 30 14:55:38 mtcdt user.info kernel: i2c /dev entries driver
Mar 30 14:55:38 mtcdt user.info kernel: at91sam9_wdt: enabled (heartbeat=15 sec, nowayout=0)
Mar 30 14:55:38 mtcdt user.info kernel: Netfilter messages via NETLINK v0.30.
Mar 30 14:55:38 mtcdt user.info kernel: nf_conntrack version 0.5.0 (3968 buckets, 15872 max)
Mar 30 14:55:38 mtcdt user.info kernel: ipip: IPv4 over IPv4 tunneling driver
Mar 30 14:55:38 mtcdt user.info kernel: gre: GRE over IPv4 demultiplexor driver
Mar 30 14:55:38 mtcdt user.info kernel: ip_gre: GRE over IPv4 tunneling driver
Mar 30 14:55:38 mtcdt user.info kernel: IPv4 over IPSec tunneling driver
Mar 30 14:55:38 mtcdt user.info kernel: ip_tables: (C) 2000-2006 Netfilter Core Team
Mar 30 14:55:38 mtcdt user.info kernel: TCP: cubic registered
Mar 30 14:55:38 mtcdt user.info kernel: Initializing XFRM netlink socket
Mar 30 14:55:38 mtcdt user.info kernel: NET: Registered protocol family 10
Mar 30 14:55:38 mtcdt user.info kernel: mip6: Mobile IPv6
Mar 30 14:55:38 mtcdt user.info kernel: sit: IPv6 over IPv4 tunneling driver
Mar 30 14:55:38 mtcdt user.info kernel: NET: Registered protocol family 17
Mar 30 14:55:38 mtcdt user.info kernel: NET: Registered protocol family 15
Mar 30 14:55:38 mtcdt user.info kernel: l2tp_core: L2TP core driver, V2.0
Mar 30 14:55:38 mtcdt user.notice kernel: Key type dns_resolver registered
Mar 30 14:55:38 mtcdt user.info kernel: at91_rtc fffffeb0.rtc: setting system clock to 2017-03-30 13:55:23 UTC (1490882123)
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2: new high-speed USB device number 2 using atmel-ehci
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2: New USB device found, idVendor=0424, idProduct=2534
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Mar 30 14:55:38 mtcdt user.info kernel: hub 1-2:1.0: USB hub found
Mar 30 14:55:38 mtcdt user.info kernel: hub 1-2:1.0: 4 ports detected
Mar 30 14:55:38 mtcdt user.info kernel: usb 2-3: new full-speed USB device number 2 using at91_ohci
Mar 30 14:55:38 mtcdt user.info kernel: usb 2-3: New USB device found, idVendor=04e2, idProduct=1412
Mar 30 14:55:38 mtcdt user.info kernel: usb 2-3: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.1: new high-speed USB device number 3 using atmel-ehci
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.1: New USB device found, idVendor=0403, idProduct=6014
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.1: Product: Single RS232-HS
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.1: Manufacturer: FTDI
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.3: new high-speed USB device number 4 using atmel-ehci
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.3: New USB device found, idVendor=1bc7, idProduct=0021
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.3: Product: Telit Wireless Module
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.3: Manufacturer: Telit wireless solutions
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.3: SerialNumber: 351579054996226
Mar 30 14:55:38 mtcdt user.notice kernel: jffs2: notice: (1) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found.
Mar 30 14:55:38 mtcdt user.info kernel: VFS: Mounted root (jffs2 filesystem) readonly on device 31:8.
Mar 30 14:55:38 mtcdt user.info kernel: devtmpfs: mounted
Mar 30 14:55:38 mtcdt user.info kernel: Freeing unused kernel memory: 168K (c053d000 - c0567000)
Mar 30 14:55:38 mtcdt user.notice kernel: jffs2: notice: (73) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found.
Mar 30 14:55:38 mtcdt user.notice kernel: jffs2: notice: (73) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found.
Mar 30 14:55:38 mtcdt daemon.info kernel: udevd[84]: starting version 182
Mar 30 14:55:38 mtcdt user.info kernel: atmel_spi f0000000.spi: version: 0x212
Mar 30 14:55:38 mtcdt user.info kernel: atmel_spi f0000000.spi: Using dma0chan1 (tx) and dma0chan2 (rx) for DMA transfers
Mar 30 14:55:38 mtcdt user.info kernel: atmel_spi f0000000.spi: Atmel SPI Controller at 0xf0000000 (irq 28)
Mar 30 14:55:38 mtcdt user.info kernel: atmel_spi f0000000.spi: master is unqueued, this is deprecated
Mar 30 14:55:38 mtcdt user.info kernel: pps_core: LinuxPPS API ver. 1 registered
Mar 30 14:55:38 mtcdt user.info kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
Mar 30 14:55:38 mtcdt user.info kernel: pps pps0: new PPS source pps.7.-1
Mar 30 14:55:38 mtcdt user.info kernel: pps pps0: Registered IRQ 32 as PPS source
Mar 30 14:55:38 mtcdt user.info kernel: atmel_spi f0004000.spi: version: 0x212
Mar 30 14:55:38 mtcdt user.info kernel: atmel_spi f0004000.spi: Using dma1chan0 (tx) and dma1chan1 (rx) for DMA transfers
Mar 30 14:55:38 mtcdt user.info kernel: atmel_spi f0004000.spi: Atmel SPI Controller at 0xf0004000 (irq 29)
Mar 30 14:55:38 mtcdt user.info kernel: atmel_spi f0004000.spi: master is unqueued, this is deprecated
Mar 30 14:55:38 mtcdt user.info kernel: tmp102 0-0048: initialized
Mar 30 14:55:38 mtcdt user.info kernel: atmel_mci f0008000.mmc: version: 0x504
Mar 30 14:55:38 mtcdt user.info kernel: atmel_mci f0008000.mmc: using dma0chan3 for DMA transfers
Mar 30 14:55:38 mtcdt user.info kernel: atmel_mci f0008000.mmc: Atmel MCI controller at 0xf0008000 irq 22, 1 slots
Mar 30 14:55:38 mtcdt user.info kernel: atmel_usba_udc 500000.gadget: MMIO registers at 0xf803c000 mapped at d0952000
Mar 30 14:55:38 mtcdt user.info kernel: atmel_usba_udc 500000.gadget: FIFO at 0x00500000 mapped at e1100000
Mar 30 14:55:38 mtcdt user.err kernel: cdc_acm 1-2.3:1.0: This device cannot do calls on its own. It is not a modem.
Mar 30 14:55:38 mtcdt user.info kernel: cdc_acm 1-2.3:1.0: ttyACM0: USB ACM device
Mar 30 14:55:38 mtcdt user.err kernel: cdc_acm 1-2.3:1.2: This device cannot do calls on its own. It is not a modem.
Mar 30 14:55:38 mtcdt user.info kernel: cdc_acm 1-2.3:1.2: ttyACM1: USB ACM device
Mar 30 14:55:38 mtcdt user.err kernel: cdc_acm 1-2.3:1.4: This device cannot do calls on its own. It is not a modem.
Mar 30 14:55:38 mtcdt user.info kernel: cdc_acm 1-2.3:1.4: ttyACM2: USB ACM device
Mar 30 14:55:38 mtcdt user.err kernel: cdc_acm 1-2.3:1.6: This device cannot do calls on its own. It is not a modem.
Mar 30 14:55:38 mtcdt user.info kernel: cdc_acm 1-2.3:1.6: ttyACM3: USB ACM device
Mar 30 14:55:38 mtcdt user.err kernel: cdc_acm 1-2.3:1.8: This device cannot do calls on its own. It is not a modem.
Mar 30 14:55:38 mtcdt user.info kernel: cdc_acm 1-2.3:1.8: ttyACM4: USB ACM device
Mar 30 14:55:38 mtcdt user.info kernel: usbcore: registered new interface driver usbserial
Mar 30 14:55:38 mtcdt user.info kernel: usbcore: registered new interface driver usbserial_generic
Mar 30 14:55:38 mtcdt user.info kernel: usbserial: USB Serial support registered for generic
Mar 30 14:55:38 mtcdt user.err kernel: cdc_acm 1-2.3:1.10: This device cannot do calls on its own. It is not a modem.
Mar 30 14:55:38 mtcdt user.info kernel: cdc_acm 1-2.3:1.10: ttyACM5: USB ACM device
Mar 30 14:55:38 mtcdt user.err kernel: cdc_acm 1-2.3:1.12: This device cannot do calls on its own. It is not a modem.
Mar 30 14:55:38 mtcdt user.info kernel: cdc_acm 1-2.3:1.12: ttyACM6: USB ACM device
Mar 30 14:55:38 mtcdt user.info kernel: usbcore: registered new interface driver ftdi_sio
Mar 30 14:55:38 mtcdt user.info kernel: usbserial: USB Serial support registered for FTDI USB Serial Device
Mar 30 14:55:38 mtcdt user.info kernel: ftdi_sio 1-2.1:1.0: FTDI USB Serial Device converter detected
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.1: Detected FT232H
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.1: Number of endpoints 2
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.1: Endpoint 1 MaxPacketSize 512
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.1: Endpoint 2 MaxPacketSize 512
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.1: Setting MaxPacketSize 512
Mar 30 14:55:38 mtcdt user.info kernel: usbcore: registered new interface driver cdc_acm
Mar 30 14:55:38 mtcdt user.info kernel: cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
Mar 30 14:55:38 mtcdt user.err kernel: vizzini 2-3:1.0: This device cannot do calls on its own. It is not a modem.
Mar 30 14:55:38 mtcdt user.info kernel: vizzini 2-3:1.0: ttyXRUSB0: XR21v14x usb uart device
Mar 30 14:55:38 mtcdt user.err kernel: vizzini 2-3:1.2: This device cannot do calls on its own. It is not a modem.
Mar 30 14:55:38 mtcdt user.info kernel: vizzini 2-3:1.2: ttyXRUSB1: XR21v14x usb uart device
Mar 30 14:55:38 mtcdt user.info kernel: usbcore: registered new interface driver vizzini
Mar 30 14:55:38 mtcdt user.info kernel: vizzini: Exar USB UART Driver for XR21V141x
Mar 30 14:55:38 mtcdt user.info kernel: usb 1-2.1: FTDI USB Serial Device converter now attached to ttyUSB0
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_io_init:829: init: v1.1.1
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:754: detected board MTCDT-0.0
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:757: sizeof: 512
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:758: vendor-id: Multi-Tech Systems
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:759: product-id: MTCDT-H5-210L
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:760: device-id: 18387648
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:761: hw-version: MTCDT-0.0
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:768: mac-addr: 00:08:00:4A:02:DB
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:770: imei: 351579054996226
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:771: capa-gps: no
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:772: capa-din: no
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:773: capa-dout: no
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:774: capa-adc: no
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:775: capa-wifi: no
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:776: capa-bluetooth: no
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:mts_id_eeprom_load:800: uuid: 7F2425B450C0A6C39667780409FE3ADE
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:load_port:688: accessory card 1 vendor-id: Multi-Tech Systems
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:load_port:689: accessory card 1 product-id: MTAC-LORA-868
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:load_port:690: accessory card 1 device-id: 18759081
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:load_port:691: accessory card 1 hw-version: MTAC-LORA-1.0
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:load_port:712: accessory card 1 eui: 00:80:00:00:00:00:BD:3A
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:lora_setup:42: loading LORA accessory card in port 1
Mar 30 14:55:38 mtcdt user.info kernel: [INFO] mts-io:load_port:653: no accessory card inserted in port 2
Mar 30 14:55:38 mtcdt user.info kernel: IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Mar 30 14:55:39 mtcdt local2.info chat[456]: abort on (NO DIAL TONE)
Mar 30 14:55:39 mtcdt local2.info chat[456]: abort on (NO DIALTONE)
Mar 30 14:55:39 mtcdt local2.info chat[456]: abort on (NO ANSWER)
Mar 30 14:55:39 mtcdt local2.info chat[456]: abort on (NO CARRIER)
Mar 30 14:55:39 mtcdt local2.info chat[456]: abort on (DELAYED)
Mar 30 14:55:39 mtcdt local2.info chat[456]: abort on (VOICE)
Mar 30 14:55:39 mtcdt local2.info chat[456]: abort on (BUSY)
Mar 30 14:55:39 mtcdt local2.info chat[456]: send (AT^M)
Mar 30 14:55:39 mtcdt local2.info chat[456]: expect (OK)
Mar 30 14:55:39 mtcdt local2.info chat[456]: AT^M^M
Mar 30 14:55:39 mtcdt local2.info chat[456]: OK
Mar 30 14:55:39 mtcdt local2.info chat[456]: -- got it
Mar 30 14:55:39 mtcdt local2.info chat[456]: send (ATZ^M)
Mar 30 14:55:39 mtcdt local2.info chat[456]: expect (OK)
Mar 30 14:55:39 mtcdt local2.info chat[456]: ^M
Mar 30 14:55:39 mtcdt local2.info chat[456]: ATZ^M^M
Mar 30 14:55:39 mtcdt local2.info chat[456]: OK
Mar 30 14:55:39 mtcdt local2.info chat[456]: -- got it
Mar 30 14:55:39 mtcdt local2.info chat[456]: send (AT+CSQ^M)
Mar 30 14:55:39 mtcdt user.info kernel: g_serial gadget: Gadget Serial v2.4
Mar 30 14:55:39 mtcdt user.info kernel: g_serial gadget: g_serial ready
Mar 30 14:55:39 mtcdt local2.info chat[456]: expect (OK)
Mar 30 14:55:39 mtcdt local2.info chat[456]: ^M
Mar 30 14:55:39 mtcdt local2.info chat[456]: AT+CSQ^M^M
Mar 30 14:55:39 mtcdt local2.info chat[456]: +CSQ: 99,99^M
Mar 30 14:55:39 mtcdt local2.info chat[456]: ^M
Mar 30 14:55:39 mtcdt local2.info chat[456]: OK
Mar 30 14:55:39 mtcdt local2.info chat[456]: -- got it
Mar 30 14:55:39 mtcdt local2.info chat[456]: send (AT+CGDCONT=1,"IP","hs.vodafone.ie"^M)
Mar 30 14:55:39 mtcdt user.notice kernel: jffs2: notice: (468) check_node_data: wrong data CRC in data node at 0x045fdf88: read 0x370468e, calculated 0xf3cba1.
Mar 30 14:55:40 mtcdt local2.info chat[456]: expect (OK)
Mar 30 14:55:40 mtcdt local2.info chat[456]: ^M
Mar 30 14:55:40 mtcdt local2.info chat[456]: AT+CGDCONT=1,"IP","hs.vodafone.ie"^M^M
Mar 30 14:55:40 mtcdt local2.info chat[456]: OK
Mar 30 14:55:40 mtcdt local2.info chat[456]: -- got it
Mar 30 14:55:40 mtcdt local2.info chat[456]: send (ATD*99***1#^M)
Mar 30 14:55:40 mtcdt local2.info chat[456]: timeout set to 120 seconds
Mar 30 14:55:40 mtcdt local2.info chat[456]: expect (CONNECT)
Mar 30 14:55:40 mtcdt local2.info chat[456]: ^M
Mar 30 14:55:40 mtcdt local2.info chat[456]: ATD*99***1#^M^M
Mar 30 14:55:40 mtcdt local2.info chat[456]: NO CARRIER
Mar 30 14:55:40 mtcdt local2.info chat[456]: -- failed
Mar 30 14:55:40 mtcdt local2.info chat[456]: Failed (NO CARRIER)
Mar 30 14:55:40 mtcdt daemon.err pppd[411]: Connect script failed
Mar 30 14:55:40 mtcdt user.info kernel: ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
Mar 30 14:55:40 mtcdt user.info kernel: ftdi_sio 1-2.1:1.0: device disconnected
Mar 30 14:55:40 mtcdt cron.info crond[497]: (CRON) STARTUP (1.4.11)
Mar 30 14:55:40 mtcdt cron.info crond[497]: (CRON) INFO (Syslog will be used instead of sendmail.)
Mar 30 14:55:40 mtcdt cron.info crond[497]: (CRON) INFO (RANDOM_DELAY will be scaled with factor 44% if used.)
Mar 30 14:55:40 mtcdt user.notice root: GwModemDaemon start
Mar 30 14:55:41 mtcdt daemon.info pppd[411]: Exit.
Mar 30 14:55:41 mtcdt user.notice reset-handler: Enabling reset-monitor for pid 512
Mar 30 15:00:02 mtcdt authpriv.info crond[561]: pam_unix(crond:session): session opened for user root by (uid=0)
Mar 30 15:00:02 mtcdt cron.info CROND[562]: (root) CMD (/usr/sbin/logrotate /etc/logrotate.conf)
Mar 30 15:00:02 mtcdt authpriv.info CROND[561]: pam_unix(crond:session): session closed for user root
Mar 30 15:00:25 mtcdt user.notice kernel: jffs2: notice: (273) check_node_data: wrong data CRC in data node at 0x0bc0fce8: read 0xe798e01a, calculated 0xbd96b57c.
Mar 30 15:00:46 mtcdt user.warn kernel: jffs2: warning: (531) jffs2_sum_write_data: Not enough space for summary, padsize = -1246
Mar 30 15:05:01 mtcdt authpriv.info crond[574]: pam_unix(crond:session): session opened for user root by (uid=0)
Mar 30 15:05:01 mtcdt cron.info CROND[575]: (root) CMD (/usr/sbin/logrotate /etc/logrotate.conf)
Mar 30 15:05:01 mtcdt authpriv.info CROND[574]: pam_unix(crond:session): session closed for user root
Mar 30 15:10:01 mtcdt authpriv.info crond[592]: pam_unix(crond:session): session opened for user root by (uid=0)
Mar 30 15:10:01 mtcdt cron.info CROND[593]: (root) CMD (/usr/sbin/logrotate /etc/logrotate.conf)
Mar 30 15:10:01 mtcdt authpriv.info CROND[592]: pam_unix(crond:session): session closed for user root
Mar 30 15:11:35 mtcdt authpriv.info login[521]: pam_unix(login:session): session opened for user root by LOGIN(uid=0)
Mar 30 15:11:35 mtcdt authpriv.notice login[594]: ROOT LOGIN on '/dev/ttyS0'


• This reply was modified 7 years, 1 month ago by Damian Christie.
• This reply was modified 7 years, 1 month ago by Damian Christie.

[Damian Christie]

Hi,

Looks like ppp has an option to turn off debugging but I can find no way to increase the debugging. Based on your suggestion that the radio may be coming up more slowly on this, is there a way I can generate an output to the system log when it is “up”? That way I can see if it’s up before the it tries to connect. Is there anything else I can try?

On a completely separate note, is the RSSI value quoted in the mlinux network server logs the resolved value i.e. is this the value before or after SNR has been taken into account??

Thanks.

[Jeff Hatch]

Damian,

From the chat output it looks like the radio is responding. The problem may still be radio related, but I am not sure. You can turn up the ppp debugging by:

Diagnostics

Messages are sent to the syslog daemon using facility LOG_DAEMON. (This can be overridden by recompiling pppd with the macro LOG_PPP defined as the desired facility.) See the syslog(8) documentation for details of where the syslog daemon will write the messages. On most systems, the syslog daemon uses the /etc/syslog.conf file to specify the destination(s) for syslog messages. You may need to edit that file to suit.

The debug option causes the contents of all control packets sent or received to be logged, that is, all LCP, PAP, CHAP, EAP, or IPCP packets. This can be useful if the PPP negotiation does not succeed or if authentication fails. If debugging is enabled at compile time, the debug option also causes other debugging messages to be logged.

Debugging can also be enabled or disabled by sending a SIGUSR1 signal to the pppd process. This signal acts as a toggle.

You can either send a SIGUSR1 to the pppd process or add the debug option to the ppp start script. It would probably be easier to try the SIGUSR1 first.

Jeff

[Author]

Posts