GSM WB6.7+ зависает wb-gsm restart_if_broken


Вот такая картина 10 часов.
Wiren Board 6.9.1 (s/n A6YXEPXP), release wb-2207 (as wb-2207)
wb-utils 3.7.0-wb4
А происходит такое, когда подключаешься к ppp по gsm а потом при активном соединении делаешь reboot.
Если перезагружать по питанию, такой беды не происходит.

root@wirenboard-A6YXEPXP:~# ls /dev| grep -e ACM -e GSM -e USB
ps ax | grep -e ppp -e pon -e ifup -e wb-gsm
ttyUSB0
ttyUSB1
ttyUSB2
root@wirenboard-A6YXEPXP:~# ps ax | grep -e ppp -e pon -e ifup -e wb-gsm
7524 ? S 0:00 ifup ppp0
7526 ? S 0:00 /bin/sh -c wb-gsm restart_if_broken
7527 ? S 0:00 /bin/bash /usr/bin/wb-gsm restart_if_broken
7822 ? S 0:00 /bin/bash /usr/bin/wb-gsm restart_if_broken
7860 ? S 0:00 /bin/bash /usr/bin/wb-gsm restart_if_broken
32101 pts/0 S+ 0:00 grep -e ppp -e pon -e ifup -e wb-gsm
root@wirenboard-A6YXEPXP:~#

в стабильном 2207 версия 3.7.0-wb105
С ней так же воспроизводится?

Обновил wb-utils
Питание не выключал, пару раз перезагрузил.
Картина та же.

При этом, даже если выключить модем wb-gsm off все равно остаются висеть процессы
wb-gsm restart_if_broken
и судя по дереву процессов зависает chat.

Да, похоже на баг, попробую воспроизвести.
Вообще в тестинге на bullseye тоже проверю.

Да, подебажил, исправим. Благодарю за то что помогаете исправить. Отличное подробное описание, внимание к деталям.

приветствую!
взяли в работу; кое-что починили; просим попробовать у себя!
вероятная причина проблемы - неаккуратная работа wb-gsm с занятыми (например, ppp) портами

изменения:

  • wb-gsm restart_if_broken починился; ifup/ifdown ppp0 перестали зависать
  • следить за деятельностью wb-gsm можно через journalctl -t wb-gsm -f
  • wb-gsm можно дёргать, когда угодно (а не в определенной фазе луны)
  • в чат-скриптах для ppp порт можно указывать - /dev/ttyGSM; т.е. всё по умолчанию

wb-utils_3.7.0-wb107~exp-1_all.deb (29.9 КБ)

1 Like

Обновил. Теперь не зависает. В логе видим следующее:
Контроллер перезагружал. По питанию не выключал.
в ppp работаю c /dev/ttyUSB2

tail -n 50 -f /var/log/messages | grep -e chat -e ppp -e sim
Nov 18 15:37:22 wirenboard-A6YXEPXP chat[16049]: ERROR
Nov 18 15:37:22 wirenboard-A6YXEPXP chat[16049]:  -- failed
Nov 18 15:37:22 wirenboard-A6YXEPXP chat[16049]: Failed (ERROR)
Nov 18 15:37:22 wirenboard-A6YXEPXP pppd[12967]: Connect script failed
Nov 18 15:37:39 wirenboard-A6YXEPXP chat[16363]: timeout set to 2 seconds
Nov 18 15:37:39 wirenboard-A6YXEPXP chat[16363]: abort on (ERROR)
Nov 18 15:37:39 wirenboard-A6YXEPXP chat[16363]: abort on (BUSY)
Nov 18 15:37:39 wirenboard-A6YXEPXP chat[16363]: send (AT^M)
Nov 18 15:37:39 wirenboard-A6YXEPXP chat[16363]: expect (OK)
Nov 18 15:37:39 wirenboard-A6YXEPXP chat[16363]: AT
Nov 18 15:37:39 wirenboard-A6YXEPXP chat[16363]: 
Nov 18 15:37:39 wirenboard-A6YXEPXP chat[16363]: 
Nov 18 15:37:39 wirenboard-A6YXEPXP chat[16363]: OK
Nov 18 15:37:39 wirenboard-A6YXEPXP chat[16363]:  -- got it
Nov 18 15:37:39 wirenboard-A6YXEPXP chat[16363]: send (^M)
Nov 18 15:37:39 wirenboard-A6YXEPXP simcard_watchdog.sh[618]: <2022-11-18 15:37:39,852//opt/simcard_watchdog/simcard_switcher.py:60/INFO>-  got exception in serial port write: UnicodeDecodeError('utf-8', b'\x14\x00\x00\x00\x00\x00\x00\x02+\x001G7>i\x00\r\x00\xc8\x00', 18, 19, 'invalid continuation byte')
Nov 18 15:37:39 wirenboard-A6YXEPXP simcard_watchdog.sh[618]: <2022-11-18 15:37:39,883//opt/simcard_watchdog/watchdog.py:200/INFO>-  bad rssi_index AT answer:
Nov 18 15:37:39 wirenboard-A6YXEPXP simcard_watchdog.sh[618]: <2022-11-18 15:37:39,888//opt/simcard_watchdog/watchdog.py:236/INFO>-  fail in signal_sender_loop, e:KeyError('bad AT answer'), skip_single_error: False
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16407]: timeout set to 5 seconds
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16407]: abort on (ERROR)
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16407]: abort on (BUSY)
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16407]: send (AT^M)
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16407]: expect (OK)
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16407]: AT
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16407]: 
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16407]: 
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16407]: OK
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16407]:  -- got it
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16407]: send (^M)
Nov 18 15:37:40 wirenboard-A6YXEPXP pppd[12967]: Serial port initialized.
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16412]: abort on (BUSY)
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16412]: abort on (NO ANSWER)
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16412]: abort on (NO CARRIER)
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16412]: abort on (ERROR)
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16412]: timeout set to 5 seconds
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16412]: send (ATZ^M)
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16412]: expect (OK)
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16412]: ATZ^M^M
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16412]: ERROR
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16412]:  -- failed
Nov 18 15:37:40 wirenboard-A6YXEPXP chat[16412]: Failed (ERROR)
Nov 18 15:37:40 wirenboard-A6YXEPXP pppd[12967]: Connect script failed
root@wirenboard-A6YXEPXP:~# ls -l /dev| grep -e ACM -e GSM -e USB
lrwxrwxrwx 1 root root          12 Nov 18 15:34 ttyGSM -> /dev/ttyGSM0
lrwxrwxrwx 1 root root          12 Nov 18 15:34 ttyGSM0 -> /dev/ttyUSB2
lrwxrwxrwx 1 root root          12 Nov 18 15:34 ttyGSM1 -> /dev/ttyUSB1
crw-rw---- 1 root dialout 188,   0 Nov 18 15:40 ttyUSB0
crw-rw---- 1 root dialout 188,   1 Nov 18 15:40 ttyUSB1
crw-rw---- 1 root dialout 188,   2 Nov 18 15:40 ttyUSB2
root@wirenboard-A6YXEPXP:~# ps ax | grep -e ppp -e pon -e ifup -e wb-gsm -e chat
12967 ?        Ss     0:00 /usr/sbin/pppd call megafon
19698 pts/0    S+     0:00 grep -e ppp -e pon -e ifup -e wb-gsm -e chat

Еще наблюдение.
Почему ошибка?

root@wirenboard-A6YXEPXP:~# wb-gsm off
root@wirenboard-A6YXEPXP:~# 
root@wirenboard-A6YXEPXP:~# 
root@wirenboard-A6YXEPXP:~# ls -l /dev| grep -e ACM -e GSM -e USB
root@wirenboard-A6YXEPXP:~# DEBUG=true wb-gsm restart_if_broken
DEBUG: main: Called from pid 28609 (bash)
DEBUG: guess_of_node: Got of_gsm_node: /soc/bus@2100000/usb@2184200/usb-hub@1/wbc-modem@2
DEBUG: restart_if_broken: Modem switched off, switch it on instead of testing the connection
DEBUG: ensure_on: switching on GSM modem using POWER FET
DEBUG: toggle: toggle GSM modem state using PWRKEY
DEBUG: ensure_on: Waiting for modem to start
DEBUG: init_usb_connection: Will wait up to 30s untill usb port becomes available
DEBUG: probe_usb_ports: Probing all modem's usb ports
DEBUG: test_connection: (port:/dev/ttyUSB0; timeout:2) => 137
DEBUG: test_connection: (port:/dev/ttyUSB1; timeout:2) => 137
DEBUG: test_connection: /dev/ttyUSB2 is not free
DEBUG: test_connection: (port:/dev/ttyUSB2; timeout:2) => 1
DEBUG: probe_usb_ports: Modem's usb ports: ttyUSB0 ttyUSB1 ttyUSB2
DEBUG: probe_usb_ports: Answered to 'AT':
Turning OFF modem's POWER FET
DEBUG: of_get_prop_gpio: /soc/bus@2100000/usb@2184200/usb-hub@1/wbc-modem@2 power-gpios
DEBUG: of_get_prop_gpio: gpio 33 4 0
DEBUG: of_gpio_to_num: Unpacked gpio 128:4:0 -> 128+4
Force exit: no valid usb-AT connection after 30s
 1: /usr/lib/wb-utils/wb-gsm-common.sh:518 init_usb_connection(...)
 2: /usr/lib/wb-utils/wb-gsm-common.sh:554 ensure_on(...)
 3: /usr/bin/wb-gsm:29 restart_if_broken(...)
Error in /usr/lib/wb-utils/wb-gsm-common.sh:71. '[[ -n $unlinked_ports ]]' exited with status 0
Call tree:
 1: /usr/lib/wb-utils/wb-gsm-common.sh:1 force_exit_handler(...)
 2: /usr/lib/wb-utils/wb-gsm-common.sh:184 force_exit(...)
 3: /usr/lib/wb-utils/wb-gsm-common.sh:518 init_usb_connection(...)
 4: /usr/lib/wb-utils/wb-gsm-common.sh:554 ensure_on(...)
 5: /usr/bin/wb-gsm:29 restart_if_broken(...)
Exiting with status 1

а потом… И он поднялся!

pon megafon
root@wirenboard-A6YXEPXP:~# tail -n 50 -f /var/log/messages | grep -e chat -e ppp -e sim
Nov 18 16:11:43 wirenboard-A6YXEPXP pppd[5954]: Device ttyUSB2 is locked by pid 30305
Nov 18 16:11:53 wirenboard-A6YXEPXP pppd[5954]: Device ttyUSB2 is locked by pid 30305
Nov 18 16:12:03 wirenboard-A6YXEPXP pppd[5954]: Device ttyUSB2 is locked by pid 30305
Nov 18 16:12:13 wirenboard-A6YXEPXP pppd[5954]: Device ttyUSB2 is locked by pid 30305
Nov 18 16:12:23 wirenboard-A6YXEPXP pppd[5954]: Device ttyUSB2 is locked by pid 30305
^C
root@wirenboard-A6YXEPXP:~# killall pppd
root@wirenboard-A6YXEPXP:~# 

И вот!

pon megafon

Nov 18 16:12:13 wirenboard-A6YXEPXP pppd[5954]: Device ttyUSB2 is locked by pid 30305
Nov 18 16:12:23 wirenboard-A6YXEPXP pppd[5954]: Device ttyUSB2 is locked by pid 30305
Nov 18 16:12:33 wirenboard-A6YXEPXP pppd[5954]: Device ttyUSB2 is locked by pid 30305
Nov 18 16:12:34 wirenboard-A6YXEPXP pppd[5954]: Terminating on signal 15
Nov 18 16:12:34 wirenboard-A6YXEPXP pppd[5954]: Exit.
Nov 18 16:12:34 wirenboard-A6YXEPXP pppd[30305]: Terminating on signal 15
Nov 18 16:12:34 wirenboard-A6YXEPXP pppd[30305]: Connect time 2.7 minutes.
Nov 18 16:12:34 wirenboard-A6YXEPXP pppd[30305]: Sent 0 bytes, received 0 bytes.
Nov 18 16:12:34 wirenboard-A6YXEPXP pppd[30305]: Connection terminated.
Nov 18 16:12:34 wirenboard-A6YXEPXP avahi-daemon[647]: Withdrawing workstation service for ppp0.
Nov 18 16:12:34 wirenboard-A6YXEPXP pppd[30305]: Exit.
Nov 18 16:12:36 wirenboard-A6YXEPXP ntpd[2218]: Deleting interface #18 ppp0, 100.88.73.78#123, interface stats: received=0, sent=0, dropped=0, active_time=162 secs
Nov 18 16:12:51 wirenboard-A6YXEPXP pppd[6403]: pppd 2.4.7 started by root, uid 0
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: timeout set to 2 seconds
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: abort on (ERROR)
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: abort on (BUSY)
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: send (AT^M)
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: expect (OK)
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: +CGEV: ME PDN DEACT 1
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: NO CARRIER
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: +CGEV: ME PDN ACT 1,4
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:08 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:09 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP wb-rules[2698]: Device "ppp0" does not exist.
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:10 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:11 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: +C
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7455]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7492]: timeout set to 2 seconds
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7492]: abort on (ERROR)
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7492]: abort on (BUSY)
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7492]: send (AT^M)
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7492]: expect (OK)
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7492]: AT
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7492]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7492]: 
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7492]: OK
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7492]:  -- got it
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7492]: send (^M)
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7541]: timeout set to 5 seconds
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7541]: abort on (ERROR)
Nov 18 16:13:12 wirenboard-A6YXEPXP chat[7541]: abort on (BUSY)
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7541]: send (AT^M)
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7541]: expect (OK)
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7541]: AT
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7541]: 
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7541]: 
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7541]: OK
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7541]:  -- got it
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7541]: send (^M)
Nov 18 16:13:13 wirenboard-A6YXEPXP pppd[6403]: Serial port initialized.
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: abort on (BUSY)
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: abort on (NO ANSWER)
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: abort on (NO CARRIER)
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: abort on (ERROR)
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: timeout set to 5 seconds
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: send (ATZ^M)
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: expect (OK)
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: ATZ^M^M
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: OK
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]:  -- got it
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: send (AT+CGDCONT=1,"IP","internet"^M)
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: expect (OK)
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: ^M
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: AT+CGDCONT=1,"IP","internet"^M^M
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: OK
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]:  -- got it
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: send (ATD*99***1#^M)
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: expect (CONNECT)
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: ^M
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: ATD*99***1#^M^M
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]: CONNECT
Nov 18 16:13:13 wirenboard-A6YXEPXP chat[7548]:  -- got it
Nov 18 16:13:13 wirenboard-A6YXEPXP pppd[6403]: Serial connection established.
Nov 18 16:13:13 wirenboard-A6YXEPXP pppd[6403]: Using interface ppp0
Nov 18 16:13:13 wirenboard-A6YXEPXP pppd[6403]: Connect: ppp0 <--> /dev/ttyUSB2
Nov 18 16:13:14 wirenboard-A6YXEPXP pppd[6403]: PAP authentication succeeded
Nov 18 16:13:14 wirenboard-A6YXEPXP pppd[6403]: kernel does not support PPP filtering
Nov 18 16:13:14 wirenboard-A6YXEPXP pppd[6403]: Could not determine remote IP address: defaulting to 10.64.64.64
Nov 18 16:13:14 wirenboard-A6YXEPXP pppd[6403]: not replacing default route to eth1 [192.168.33.254]
Nov 18 16:13:14 wirenboard-A6YXEPXP pppd[6403]: local  IP address 10.7.208.206
Nov 18 16:13:14 wirenboard-A6YXEPXP pppd[6403]: remote IP address 10.64.64.64
Nov 18 16:13:14 wirenboard-A6YXEPXP pppd[6403]: primary   DNS address 10.97.52.77
Nov 18 16:13:15 wirenboard-A6YXEPXP pppd[6403]: secondary DNS address 10.97.52.68
Nov 18 16:13:16 wirenboard-A6YXEPXP ntpd[2218]: Listen normally on 19 ppp0 10.7.208.206:123
root@wirenboard-A6YXEPXP:~# ifconfig ppp0
ppp0: flags=4305<UP,POINTOPOINT,RUNNING,NOARP,MULTICAST>  mtu 1500
        inet 10.7.208.206  netmask 255.255.255.255  destination 10.64.64.64
        ppp  txqueuelen 3  (Point-to-Point Protocol)
        RX packets 5  bytes 62 (62.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 6  bytes 101 (101.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

приветствую!

предполагаю, ошибка - потому, что вообще все порты модема заняты (предполагаю, watchdog-скриптом); кажется, wb-gsm именно так и ругнулся

кстати, хотелось бы взглянуть на скрипт вочдога, если можно:)
(в частности, интересует: ходит ли он в тот же порт, что и pppd; как часто ходит; проверяет ли занятость порта; …)
если интересует уровень связи - можно ходить через второй порт модема (не занятый pppd)

в общем случае - поведение вида “после включения не работало-не работало; через 5 минут всё заработало” выглядит примерно так: pppd, видя непорядок, периодически дёргает wb-gsm; в какой-то момент времени скрипт вочдога отпускает порты, и всё запускается

p.s. про вочдог - всё это предположения без кода

Давайте упростим. Дисейблю этот вочдог и убирпем его из нашего уравнения.
Пытаемся обеспечить автостарт ppp штатными способами из wiki. (не автостартует)
Что имеем:
image
Что мы имеем после перезапуска по reboot контроллера.


Пустоту.
Далее:

DEBUG: wb_of_parse: Parsing hardware-specific environment from OF
DEBUG: of_get_prop_gpio: /wirenboard/gpios/A1_OUT io-gpios
DEBUG: of_get_prop_gpio: gpio 34 15 0
DEBUG: of_gpio_to_num: Unpacked gpio 64:15:0 -> 64+15
DEBUG: of_get_prop_gpio: /wirenboard/gpios/A4_IN io-gpios
DEBUG: of_get_prop_gpio: gpio 34 27 1
DEBUG: of_gpio_to_num: Unpacked gpio 64:27:1 -> 64+27
DEBUG: of_get_prop_gpio: /wirenboard/gpios/A1_IN io-gpios
DEBUG: of_get_prop_gpio: gpio 34 14 1
DEBUG: of_gpio_to_num: Unpacked gpio 64:14:1 -> 64+14
DEBUG: of_get_prop_gpio: /wirenboard/gpios/5V_OUT io-gpios
DEBUG: of_get_prop_gpio: gpio 42 27 0
DEBUG: of_gpio_to_num: Unpacked gpio 0:27:0 -> 0+27
DEBUG: of_get_prop_gpio: /wirenboard/gpios/A2_OUT io-gpios
DEBUG: of_get_prop_gpio: gpio 34 16 0
DEBUG: of_gpio_to_num: Unpacked gpio 64:16:0 -> 64+16
DEBUG: of_get_prop_gpio: /wirenboard/gpios/A3_IN io-gpios
DEBUG: of_get_prop_gpio: gpio 34 28 1
DEBUG: of_gpio_to_num: Unpacked gpio 64:28:1 -> 64+28
DEBUG: of_get_prop_gpio: /wirenboard/gpios/W2_IN io-gpios
DEBUG: of_get_prop_gpio: gpio 42 11 1
DEBUG: of_gpio_to_num: Unpacked gpio 0:11:1 -> 0+11
DEBUG: of_get_prop_gpio: /wirenboard/gpios/A3_OUT io-gpios
DEBUG: of_get_prop_gpio: gpio 34 17 0
DEBUG: of_gpio_to_num: Unpacked gpio 64:17:0 -> 64+17
DEBUG: of_get_prop_gpio: /wirenboard/gpios/V_OUT io-gpios
DEBUG: of_get_prop_gpio: gpio 34 9 0
DEBUG: of_gpio_to_num: Unpacked gpio 64:9:0 -> 64+9
DEBUG: of_get_prop_gpio: /wirenboard/gpios/V_OUT_OK io-gpios
DEBUG: of_get_prop_gpio: gpio 34 8 0
DEBUG: of_gpio_to_num: Unpacked gpio 64:8:0 -> 64+8
DEBUG: of_get_prop_gpio: /wirenboard/gpios/A2_IN io-gpios
DEBUG: of_get_prop_gpio: gpio 34 13 1
DEBUG: of_gpio_to_num: Unpacked gpio 64:13:1 -> 64+13
DEBUG: of_get_prop_gpio: /wirenboard/gpios/A4_OUT io-gpios
DEBUG: of_get_prop_gpio: gpio 34 18 0
DEBUG: of_gpio_to_num: Unpacked gpio 64:18:0 -> 64+18
DEBUG: of_get_prop_gpio: /wirenboard/gpios/W1_IN io-gpios
DEBUG: of_get_prop_gpio: gpio 34 4 1
DEBUG: of_gpio_to_num: Unpacked gpio 64:4:1 -> 64+4
DEBUG: of_get_prop_gpio: //soc/bus@2100000/usb@2184200/usb-hub@1/wbc-modem@2 power-gpios
DEBUG: of_get_prop_gpio: gpio 33 4 0
DEBUG: of_gpio_to_num: Unpacked gpio 128:4:0 -> 128+4
DEBUG: of_get_prop_gpio: //soc/bus@2100000/usb@2184200/usb-hub@1/wbc-modem@2 pwrkey-gpios
DEBUG: of_get_prop_gpio: gpio 34 20 0
DEBUG: of_gpio_to_num: Unpacked gpio 64:20:0 -> 64+20
DEBUG: of_get_prop_gpio: //soc/bus@2100000/usb@2184200/usb-hub@1/wbc-modem@2 status-gpios
DEBUG: of_get_prop_gpio: gpio 34 19 1
DEBUG: of_gpio_to_num: Unpacked gpio 64:19:1 -> 64+19
DEBUG: of_get_prop_gpio: //soc/bus@2100000/usb@2184200/usb-hub@1/wbc-modem@2 simselect-gpios
DEBUG: of_get_prop_gpio: gpio 34 24 0
DEBUG: of_gpio_to_num: Unpacked gpio 64:24:0 -> 64+24
DEBUG: main: Called from pid 14814 (bash)
DEBUG: guess_of_node: Got of_gsm_node: /soc/bus@2100000/usb@2184200/usb-hub@1/wbc-modem@2
DEBUG: restart_if_broken: Modem switched off, switch it on instead of testing the connection
DEBUG: ensure_on: switching on GSM modem using POWER FET
DEBUG: toggle: toggle GSM modem state using PWRKEY
DEBUG: ensure_on: Waiting for modem to start
DEBUG: init_usb_connection: Will wait up to 30s untill usb port becomes available
DEBUG: probe_usb_ports: Probing all modem's usb ports
DEBUG: test_connection: (port:/dev/ttyUSB0; timeout:2) => 137
DEBUG: test_connection: (port:/dev/ttyUSB1; timeout:2) => 0
DEBUG: test_connection: (port:/dev/ttyUSB2; timeout:2) => 0
DEBUG: probe_usb_ports: Modem's usb ports: ttyUSB0 ttyUSB1 ttyUSB2
DEBUG: probe_usb_ports: Answered to 'AT': /dev/ttyUSB1 /dev/ttyUSB2
DEBUG: init_usb_connection: Got modem model a7600x from dtso => reversing port symlinks
DEBUG: link_ports: /dev/ttyUSB2 /dev/ttyUSB1 => /dev/ttyGSM0 /dev/ttyGSM1
DEBUG: link_ports: /dev/ttyGSM0 => /dev/ttyGSM
DEBUG: test_connection: (port:/dev/ttyGSM; timeout:5) => 0
root@wirenboard-A6YXEPXP:~# ls -l /dev| grep -e ACM -e GSM -e USB
lrwxrwxrwx 1 root root          12 Nov 22 12:56 ttyGSM -> /dev/ttyGSM0
lrwxrwxrwx 1 root root          12 Nov 22 12:56 ttyGSM0 -> /dev/ttyUSB2
lrwxrwxrwx 1 root root          12 Nov 22 12:56 ttyGSM1 -> /dev/ttyUSB1
crw-rw---- 1 root dialout 188,   0 Nov 22 12:56 ttyUSB0
crw-rw---- 1 root dialout 188,   1 Nov 22 12:56 ttyUSB1
crw-rw---- 1 root dialout 188,   2 Nov 22 12:56 ttyUSB2
root@wirenboard-A6YXEPXP:~# 

И наконец.


Вуаля!
Но почему не поднимается модем при перезапуске контроллера автоматом? Что-то не так в последовательности инициализаций служб и устройств? Я даже не понимаю как лог собрать.

Да, похоже на гонку в момент запуска.
В логах есть от chat записи?
Ну и если первый pre-up sleep 10
увеличить, до 20 для проверки гипотезы - при запуске поднимается?

Попробуйте обновить все остальные пакеты.

apt update
apt upgrade

Еще в пакете wb-hwconf-manager было важное исправление в версии v1.52.7-wb101

  * starting before networking.service
  This fixes race, when networking tries to bring up ppp on not configured modem

Пришлите, пожалуйста, еще архив с диагностической информацией контроллера. Создание архива описано в документации.

1 Like
  1. Обновление не помогло.
  2. 30 сек в первом слипе помогло.
  3. А 20 сек не помогло.

еще раз перезагрузил с 30 сек.
но теперь по кругу гоняет вот такой лог: У вас нет понимания почему такое происходить может?

Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13025]:  -- got it
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13025]: send (^M)
Nov 22 14:13:41 wirenboard-A6YXEPXP pppd[7826]: Serial port initialized.
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13030]: abort on (BUSY)
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13030]: abort on (NO ANSWER)
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13030]: abort on (NO CARRIER)
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13030]: abort on (ERROR)
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13030]: timeout set to 5 seconds
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13030]: send (ATZ^M)
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13030]: expect (OK)
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13030]: ATZ^M^M
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13030]: OK
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13030]:  -- got it
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13030]: send (AT+CGDCONT=1,"IP","internet"^M)
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13030]: expect (OK)
Nov 22 14:13:41 wirenboard-A6YXEPXP chat[13030]: ^M
Nov 22 14:13:42 wirenboard-A6YXEPXP chat[13030]: AT+CGDCONT=1,"IP","internet"^M^M
Nov 22 14:13:42 wirenboard-A6YXEPXP chat[13030]: OK
Nov 22 14:13:42 wirenboard-A6YXEPXP chat[13030]:  -- got it
Nov 22 14:13:42 wirenboard-A6YXEPXP chat[13030]: send (ATD*99***1#^M)
Nov 22 14:13:42 wirenboard-A6YXEPXP chat[13030]: expect (CONNECT)
Nov 22 14:13:42 wirenboard-A6YXEPXP chat[13030]: ^M
Nov 22 14:13:42 wirenboard-A6YXEPXP chat[13030]: ATD*99***1#^M^M
Nov 22 14:13:42 wirenboard-A6YXEPXP chat[13030]: CONNECT
Nov 22 14:13:42 wirenboard-A6YXEPXP chat[13030]:  -- got it
Nov 22 14:13:42 wirenboard-A6YXEPXP pppd[7826]: Serial connection established.
Nov 22 14:13:42 wirenboard-A6YXEPXP pppd[7826]: Using interface ppp0
Nov 22 14:13:42 wirenboard-A6YXEPXP pppd[7826]: Connect: ppp0 <--> /dev/ttyUSB2
Nov 22 14:13:43 wirenboard-A6YXEPXP pppd[7826]: PAP authentication succeeded
Nov 22 14:13:43 wirenboard-A6YXEPXP pppd[7826]: kernel does not support PPP filtering
Nov 22 14:13:43 wirenboard-A6YXEPXP pppd[7826]: LCP terminated by peer
Nov 22 14:13:46 wirenboard-A6YXEPXP pppd[7826]: Connection terminated.
Nov 22 14:13:46 wirenboard-A6YXEPXP avahi-daemon[544]: Withdrawing workstation service for ppp0.
Nov 22 14:13:47 wirenboard-A6YXEPXP pppd[7826]: Modem hangup

И еще вопрос. А не лишнее ли упоминание wb-gsm restart_if_broken вот тут?

А много ль устройств в wb-hardware?

Ну и архив диагностический давайте, чтобы не спрашивать про логи.

[quote=“Vini74, post:17, topic:13402”]
но теперь по кругу гоняет вот такой лог: У вас нет понимания почему такое происходить может?
/quote]

ls -l /dev |grep tty``` надо, посмотрим куда ссылается /dev/ttyUSB2

В общем можно убрать, так как при отсутствии порта (выключенном модеме) все равно не выполнится.

diag_output_A6YXEPXP_2022-11-23-11.17.49.zip (84.7 КБ)

приветствую!

слипы, конечно, вариант плохой; постараемся от них избавиться

есть проблема: у нас не получается воспроизвести такое же поведение (с wb-utils_3.7.0-wb107~exp-1)
что мы делаем:

  1. Берем чистый контроллер (wb6.7+); вставляем туда wbc-4g (рабочая sim-карта в sim1; антенна - прикручена); накатываем factoryreset с wb-2207 (вот этот, например)
  2. apt update; apt upgrade -y
  3. выставляем модем в webui
  4. настраиваем ppp, как в этой секции вики (прописываем в /etc/network/interfaces)
  5. прописываем /dev/ttyUSB2 в чат-скрипте (в нашем случае, мтс); кстати, настоятельно не рекомендуем так делать: с wb-utils_3.7.0-wb107~exp-1, wb-gsm сам симлинкает нужный для ppp порт на /dev/ttyGSM
  6. всё работает (и при перезагрузке, и при ifup/ifdown ppp0)

отличаются ли как-то действия на Вашей стороне? (например, запущены свои systemd-сервисы)
если есть возможность проделать то же самое на чистом контроллере - было бы здорово! (назовём это “Эксперимент 1”)

глядя в логи, пока что есть только одна гипотеза - гонка сетей и wb-hwconf-manager.service
посему - попрошу Вас (на контроллере с wb-utils_3.7.0-wb107~exp-1) (Эксперимент 2) :

  1. прислать картинку systemd-analyze plot > bootup_ppp.svg, когда ppp не поднялся после перезагрузки
  2. поставить новый wb-hwconf-manager wb-hwconf-manager_1.52.7-wb103~exp-1_all.deb (65.6 КБ); убрать слипы из /etc/network/interfaces; посмотреть, не ушла ли проблема
  3. если после п.2 проблема так и осталась - предлагаю мне подключится к Вашему контроллеру (например, по anydesk; в удобное Вам время (по МСК; рабочие дни); хочется minicom и ssh на wb)

p.s. хочется информацию по версии модуля модема (наклеечка вида “v1.2.3A”; а еще лучше - прям фотографии модемного модуля с наклеечками и imei, если есть возможность)