Join Log in
Score:0
Gustavo avatar Server

Lost of PPP Connection between Debian <--> PDA / HandHeld using SynCE

sz flag
Gustavo

I am currently able to connect a handheld to the PC running Linux with a very old Ubuntu 14.04, adding repository PPA for SynCE to source list. Now, the goal is to update the operating system, I chose Debian Buster where I have successfully installed the DEB packages from the same repository in its version for Ubuntu Xenial.

In Debian, USB serial device is recognized and connects with ttyUSB bus, obtains an IP address and disconnects after a few seconds (two, max three). I have done a PPP debug (options debug dump & kdebug), everything seems normal:

pppd options in effect:
debug       # (from /etc/ppp/options)
kdebug 7        # (from /etc/ppp/options)
logfile /tmp/pppd.log       # (from /etc/ppp/options)
linkname synce-device0      # (from command line)
dump        # (from /etc/ppp/options)
noauth      # (from command line)
/dev/ttyUSB0        # (from command line)
115200      # (from command line)
lock        # (from /etc/ppp/options)
connect /usr/lib/synce-core/synce-serial-chat       # (from command line)
record /tmp/pppd.pcap       # (from /etc/ppp/options)
crtscts     # (from command line)
local       # (from command line)
asyncmap 0      # (from /etc/ppp/options)
lcp-echo-failure 4      # (from /etc/ppp/options)
lcp-echo-interval 30        # (from /etc/ppp/options)
hide-password       # (from /etc/ppp/options)
ms-dns xxx # [don't know how to print value]        # (from command line)
nodefaultroute      # (from command line)
192.168.131.1:192.168.131.129       # (from command line)
noipx       # (from /etc/ppp/options)
Removed stale lock on ttyUSB0 (pid 4366)
Script /usr/lib/synce-core/synce-serial-chat finished (pid 4435), status = 0x0
Serial connection established.
using channel 14
Using interface ppp0
Connect: ppp0 <--> /dev/pts/3
rcvd [LCP ConfReq id=0x0 <mru 1500> <asyncmap 0x0> <pcomp> <accomp>]
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xf230f2eb> <pcomp> <accomp>]
sent [LCP ConfAck id=0x0 <mru 1500> <asyncmap 0x0> <pcomp> <accomp>]
rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xf230f2eb> <pcomp> <accomp>]
sent [LCP EchoReq id=0x0 magic=0xf230f2eb]
sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 192.168.131.1>]
rcvd [CCP ConfReq id=0x0 <mppe -H -M -S -L -D +C>]
sent [CCP ConfRej id=0x0 <mppe -H -M -S -L -D +C>]
rcvd [IPCP ConfReq id=0x2 <compress VJ 0f 00> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-wins 0.0.0.0> <ms-dns2 0.0.0.0> <ms-wins 0.0.0.0>]
sent [IPCP ConfRej id=0x2 <ms-wins 0.0.0.0> <ms-wins 0.0.0.0>]
rcvd [IPV6CP ConfReq id=0x0 <addr fe80::4283:deff:feae:dec9>]
Unsupported protocol 'IPv6 Control Protocol' (0x8057) received
sent [LCP ProtRej id=0x2 80 57 01 00 00 0e 01 0a 42 83 de ff fe ae de c9]
rcvd [LCP EchoRep id=0x0 magic=0x0]
rcvd [CCP ConfRej id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
sent [CCP ConfReq id=0x2]
rcvd [IPCP ConfAck id=0x1 <compress VJ 0f 01> <addr 192.168.131.1>]
rcvd [CCP ConfReq id=0x1]
sent [CCP ConfAck id=0x1]
rcvd [IPCP ConfReq id=0x3 <compress VJ 0f 00> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
sent [IPCP ConfNak id=0x3 <addr 192.168.131.129> <ms-dns1 192.168.131.1> <ms-dns2 192.168.131.1>]
rcvd [CCP ConfNak id=0x2 <mppe -H -M -S -L -D +C>]
sent [CCP ConfReq id=0x3]
rcvd [IPCP ConfReq id=0x4 <compress VJ 0f 00> <addr 192.168.131.129> <ms-dns1 192.168.131.1> <ms-dns2 192.168.131.1>]
sent [IPCP ConfAck id=0x4 <compress VJ 0f 00> <addr 192.168.131.129> <ms-dns1 192.168.131.1> <ms-dns2 192.168.131.1>]
local  IP address 192.168.131.1
remote IP address 192.168.131.129
Script /etc/ppp/ip-up started (pid 4444)
rcvd [CCP ConfAck id=0x3]
Script /etc/ppp/ip-up finished (pid 4444), status = 0x0

In UDEV, I see that after the "add" event, from the kernel, it fires a "remove", without having disconnected the device. It is striking that the event is associated only with the ppp0 network device.

KERNEL[13133.932298] add      /devices/pci0000:00/0000:00:06.0/usb2/2-2 (usb)
KERNEL[13133.941859] add      /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0 (usb)
KERNEL[13133.946512] add      /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0/ttyUSB0 (usb-serial)
KERNEL[13133.946847] add      /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0/ttyUSB0/tty/ttyUSB0 (tty)
KERNEL[13133.946887] bind     /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0/ttyUSB0 (usb-serial)
KERNEL[13133.946930] bind     /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0 (usb)
KERNEL[13133.947016] bind     /devices/pci0000:00/0000:00:06.0/usb2/2-2 (usb)
UDEV  [13133.951550] add      /devices/pci0000:00/0000:00:06.0/usb2/2-2 (usb)
UDEV  [13133.967665] add      /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0 (usb)
UDEV  [13133.969926] add      /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0/ttyUSB0 (usb-serial)
UDEV  [13133.993251] add      /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0/ttyUSB0/tty/ttyUSB0 (tty)
UDEV  [13134.002291] bind     /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0/ttyUSB0 (usb-serial)
UDEV  [13134.003803] bind     /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0 (usb)
UDEV  [13134.004620] bind     /devices/pci0000:00/0000:00:06.0/usb2/2-2 (usb)
KERNEL[13134.445488] add      /devices/virtual/net/ppp0 (net)
KERNEL[13134.445509] add      /devices/virtual/net/ppp0/queues/rx-0 (queues)
KERNEL[13134.445519] add      /devices/virtual/net/ppp0/queues/tx-0 (queues)
UDEV  [13134.498959] add      /devices/virtual/net/ppp0 (net)
UDEV  [13134.510588] add      /devices/virtual/net/ppp0/queues/rx-0 (queues)
UDEV  [13134.514145] add      /devices/virtual/net/ppp0/queues/tx-0 (queues)
<< a little few seconds later >>
KERNEL[13137.624110] remove   /devices/virtual/net/ppp0/queues/rx-0 (queues)
KERNEL[13137.624144] remove   /devices/virtual/net/ppp0/queues/tx-0 (queues)
KERNEL[13137.624169] remove   /devices/virtual/net/ppp0 (net)
UDEV  [13137.644633] remove   /devices/virtual/net/ppp0/queues/tx-0 (queues)
UDEV  [13137.644791] remove   /devices/virtual/net/ppp0/queues/rx-0 (queues)
UDEV  [13137.659488] remove   /devices/virtual/net/ppp0 (net)

The event is related to the network interface or the network protocol, but I have not seen anything that causes it. Looked at the network traffic with Whireshark (record to pcap file), I have not found any clue. I have compared with the connection in Ubuntu and I do not see anything. In Ubuntu, despite the RSTs, the connection is never lost (see below image)

https://i.stack.imgur.com/c0RKA.png

On Debian, it is lost abruptly.

https://i.stack.imgur.com/43vtk.png

The objective is to have a TCP/IP stable connection between the USB serial device and Linux PC: ppp0 <--> /dev/ttyUSB0 Currently, with Debian, the connection is lost in a few seconds (two or three)...

Jan 18 20:26:56 debian10 pppd[1590]: local  IP address 192.168.131.1
Jan 18 20:26:56 debian10 pppd[1590]: remote IP address 192.168.131.129
Jan 18 20:26:56 debian10 dccm[1505]: DEBUG: synce_device_manager_check_interface_cb: address ready
Jan 18 20:26:56 debian10 dccm[1505]: DEBUG: synce_device_manager_create_device: found device interface for /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0/ttyUSB0/tty/ttyUSB0
Jan 18 20:26:56 debian10 dccm[1505]: DEBUG: synce_device_manager_create_device: listening for device /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0/ttyUSB0/tty/ttyUSB0
Jan 18 20:26:56 debian10 dccm[1505]: DEBUG: synce_device_manager_create_device: NOT triggering connection
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_manager_client_connected_cb: have a connection to port 5679
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_manager_client_connected_cb: creating device object for /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0/ttyUSB0/tty/ttyUSB0
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_set_property: running for device /devices/pci0000:00/0000:00:06.0/usb2/2-2/2-2:1.0/ttyUSB0/tty/ttyUSB0
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_initable_init: connecting to udev
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: info buffer length = 138
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: offset 0: unknown: guint32 ?: 40
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: offset 4: os_major: guint8: 6
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: offset 5: os_minor: guint8: 0
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: offset 6: unknown, build number ?: guint16 ?: 0
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: offset 8: cpu_type: guint16: 2577
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: offset 10: unknown: guint16 ?: 0
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: offset 12: unknown: guint32 ?: 0
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: offset 16: cur_partner_id: guint32: 0
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: offset 20: second partner id ?: guint32 ?: 0
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: offset 24: offset to device name: guint32: 40
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: offset 28: offset to platform name: guint32: 74
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: offset 32: offset to model name: guint32: 104
Jan 18 20:26:57 debian10 dccm[1505]: Message: synce_device_dbus_init: registering object path '/org/synce/dccm/Device/_devices_pci0000_00_0000_00_06_0_usb2_2_2_2_2_1_0_ttyUSB0_tty_ttyUSB0'
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_manager_device_obj_path_changed_cb: sending connected signal for /org/synce/dccm/Device/_devices_pci0000_00_0000_00_06_0_usb2_2_2_2_2_1_0_ttyUSB0_tty_ttyUSB0
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_dbus_init: obj_path set to /org/synce/dccm/Device/_devices_pci0000_00_0000_00_06_0_usb2_2_2_2_2_1_0_ttyUSB0_tty_ttyUSB0
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: get_password_flag_text: setting password flags unset
Jan 18 20:26:57 debian10 dccm[1505]: DEBUG: synce_device_legacy_info_received: setting CTRL_STATE_CONNECTED
Jan 18 20:26:58 debian10 dccm[1505]: DEBUG: gudev_uevent_callback: received uevent **remove** for device /sys/devices/virtual/net/ppp0/queues/tx-0
Jan 18 20:26:58 debian10 dccm[1505]: DEBUG: gudev_uevent_callback: received uevent **remove** for device /sys/devices/virtual/net/ppp0/queues/rx-0
Jan 18 20:26:58 debian10 dccm[1505]: DEBUG: gudev_uevent_callback: received uevent **remove** for device /sys/devices/virtual/net/ppp0

How can I detect what is happening?, What can be the cause for the kernel to remove the ppp0 device? Any answer that helps to solve this problem will be highly appreciated, even if there is another way to connect a USB serial device, I don't know if there is.

99
1 + 0
usb
Score:0
Gustavo avatar Server
sz flag
Gustavo

The udev manual give me the response:

Starting daemons or other long-running processes is not allowed; the forked processes, detached or not, will be unconditionally killed after the event handling has finished. In order to activate long-running processes from udev rules, provide a service unit and pull it in from a udev device using the SYSTEMD_WANTS device property.

Newer udev versions (from Ubuntu 16 and Debian 8) prevents you from starting long-lived background processes in RUN or PROGRAM scripts by having a strict time limit for udev transactions and processes spawned by them. As for the long-running process restriction on udev-spawned scripts, if you start something in the background, as long as the actual script udev launches terminates quickly. Udev uses cgroups to seek-n-destroy spawned tasks.

The systemd route is the right way, since starting long-running processes from udev is not recommended.

+ 0
ธงชาติไทย
Elon Musk
I sit in a Tesla and translated this thread with Ai:

mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.