https://gitlab.synchro.net/main/sbbs/-/issues/662#note_4337
This is going to be a puzzler.
Running from the command line, no dice.
~~~
root@wibble:/usr/local/etc# /usr/local/bin/sexpots /usr/local/etc/sexpots-line1.ini -syslog=sexpots-line1
Synchronet External POTS Support v2.0-Linux Copyright 2023 Rob Swindell
Oct 16 14:38:01 wibble sexpots-line1: Reading /usr/local/etc/sexpots-line1.ini Oct 16 14:38:01 wibble sexpots-line1: Synchronet Communications I/O Library for Linux v1.19
Oct 16 14:38:01 wibble sexpots-line1: Build Apr 26 2023 17:36:57 GCC 11.3.0
Oct 16 14:38:01 wibble sexpots-line1: TCP Host: endofthelinebbs.com
Oct 16 14:38:01 wibble sexpots-line1: TCP Port: 23
Oct 16 14:38:01 wibble sexpots-line1: Opening Communications Device (COM Port): /dev/ttyACM0
Oct 16 14:38:01 wibble sexpots-line1: COM Port device handle: 3
Oct 16 14:38:01 wibble sexpots-line1: COM Port DTE rate: 0 bps
Oct 16 14:38:01 wibble sexpots-line1: Initializing modem:
Oct 16 14:38:01 wibble sexpots-line1: Modem Command: AT&F1s0=0m0l1s48=7s36=5&W Oct 16 14:38:01 wibble sexpots-line1: ERROR 11 sending modem command (AT&F1s0=0m0l1s48=7s36=5&W) on /dev/ttyACM0
Oct 16 14:38:01 wibble sexpots-line1: Retry #1: sending modem command (AT&F1s0=0m0l1s48=7s36=5&W) on /dev/ttyACM0
Oct 16 14:38:01 wibble sexpots-line1: Dropping DTR on /dev/ttyACM0
Oct 16 14:38:01 wibble sexpots-line1: Raising DTR on /dev/ttyACM0
Oct 16 14:38:01 wibble sexpots-line1: Modem Command: AT&F1s0=0m0l1s48=7s36=5&W Oct 16 14:38:01 wibble sexpots-line1: ERROR 11 sending modem command (AT&F1s0=0m0l1s48=7s36=5&W) on /dev/ttyACM0
Oct 16 14:38:01 wibble sexpots-line1: Retry #2: sending modem command (AT&F1s0=0m0l1s48=7s36=5&W) on /dev/ttyACM0
Oct 16 14:38:01 wibble sexpots-line1: Dropping DTR on /dev/ttyACM0
Oct 16 14:38:02 wibble sexpots-line1: Raising DTR on /dev/ttyACM0
Oct 16 14:38:02 wibble sexpots-line1: Modem Command: AT&F1s0=0m0l1s48=7s36=5&W Oct 16 14:38:02 wibble sexpots-line1: ERROR 11 sending modem command (AT&F1s0=0m0l1s48=7s36=5&W) on /dev/ttyACM0
Oct 16 14:38:02 wibble sexpots-line1: Modem command (AT&F1s0=0m0l1s48=7s36=5&W) failure on /dev/ttyACM0 (3 attempts)
Oct 16 14:38:02 wibble sexpots-line1: Cleaning up ...
Oct 16 14:38:02 wibble sexpots-line1: Done (handled 0 calls).
~~~
Running through strace, different result...
~~~
root@wibble:/usr/local/etc# strace -o f -ff -s 65535 /usr/local/bin/sexpots /usr/local/etc/sexpots-line1.ini -syslog=sexpots-line1
Synchronet External POTS Support v2.0-Linux Copyright 2023 Rob Swindell
Oct 16 14:39:24 wibble sexpots-line1: Reading /usr/local/etc/sexpots-line1.ini Oct 16 14:39:24 wibble sexpots-line1: Synchronet Communications I/O Library for Linux v1.19
Oct 16 14:39:24 wibble sexpots-line1: Build Apr 26 2023 17:36:57 GCC 11.3.0
Oct 16 14:39:24 wibble sexpots-line1: TCP Host: endofthelinebbs.com
Oct 16 14:39:24 wibble sexpots-line1: TCP Port: 23
Oct 16 14:39:24 wibble sexpots-line1: Opening Communications Device (COM Port): /dev/ttyACM0
Oct 16 14:39:24 wibble sexpots-line1: COM Port device handle: 3
Oct 16 14:39:24 wibble sexpots-line1: COM Port DTE rate: 0 bps
Oct 16 14:39:24 wibble sexpots-line1: Initializing modem:
Oct 16 14:39:24 wibble sexpots-line1: Modem Command: AT&F1s0=0m0l1s48=7s36=5&W Oct 16 14:39:24 wibble sexpots-line1: Waiting for Modem Response ...
Oct 16 14:39:29 wibble sexpots-line1: Modem Response TIMEOUT (5 seconds) on /dev/ttyACM0
Oct 16 14:39:29 wibble sexpots-line1: Retry #1: sending modem command (AT&F1s0=0m0l1s48=7s36=5&W) on /dev/ttyACM0
Oct 16 14:39:29 wibble sexpots-line1: Dropping DTR on /dev/ttyACM0
Oct 16 14:39:29 wibble sexpots-line1: Raising DTR on /dev/ttyACM0
Oct 16 14:39:29 wibble sexpots-line1: Modem Command: AT&F1s0=0m0l1s48=7s36=5&W Oct 16 14:39:29 wibble sexpots-line1: Waiting for Modem Response ...
Oct 16 14:39:29 wibble sexpots-line1: Modem Response: AT&F1s0=0m0l1s48=7s36=5&W Oct 16 14:39:29 wibble sexpots-line1: Enabling modem Caller-ID:
Oct 16 14:39:29 wibble sexpots-line1: Modem Command: AT#CID=1
Oct 16 14:39:29 wibble sexpots-line1: Waiting for Modem Response ...
Oct 16 14:39:30 wibble sexpots-line1: Modem Response: OK
Oct 16 14:39:30 wibble sexpots-line1: Waiting for incoming call (Ring Indication) ...
~~~
the log looks something like this...
~~~
sendto(4, "<14>Oct 16 14:39:24 sexpots-line1: Opening Communications Device (COM Port): /dev/ttyACM0", 89, MSG_NOSIGNAL, NULL, 0) = 89
openat(AT_FDCWD, "/dev/ttyACM0", O_RDWR|O_NONBLOCK) = 3
ioctl(3, TCGETS, {B0 -opost -isig -icanon -echo ...}) = 0
ioctl(3, TCGETS, {B0 -opost -isig -icanon -echo ...}) = 0
ioctl(3, SNDCTL_TMR_START or TCSETS, {B0 -opost -isig -icanon -echo ...}) = 0 ioctl(3, TCGETS, {B0 -opost -isig -icanon -echo ...}) = 0
sendto(4, "<14>Oct 16 14:39:24 sexpots-line1: COM Port device handle: 3", 60, MSG_NOSIGNAL, NULL, 0) = 60
ioctl(3, TCGETS, {B0 -opost -isig -icanon -echo ...}) = 0
ioctl(3, TCGETS, {B0 -opost -isig -icanon -echo ...}) = 0
ioctl(3, SNDCTL_TMR_START or TCSETS, {B0 -opost -isig -icanon -echo ...}) = 0 ioctl(3, TCGETS, {B0 -opost -isig -icanon -echo ...}) = 0
ioctl(3, TCGETS, {B0 -opost -isig -icanon -echo ...}) = 0
ioctl(3, TCGETS, {B0 -opost -isig -icanon -echo ...}) = 0
ioctl(3, SNDCTL_TMR_START or TCSETS, {B0 -opost -isig -icanon -echo ...}) = 0 ioctl(3, TCGETS, {B0 -opost -isig -icanon -echo ...}) = 0
ioctl(3, TCGETS, {B0 -opost -isig -icanon -echo ...}) = 0
sendto(4, "<14>Oct 16 14:39:24 sexpots-line1: COM Port DTE rate: 0 bps", 59, MSG_NOSIGNAL, NULL, 0) = 59
ioctl(3, TIOCMBIS, [TIOCM_DTR]) = 0
sendto(4, "<14>Oct 16 14:39:24 sexpots-line1: Initializing modem:", 54, MSG_NOSIGNAL, NULL, 0) = 54
sendto(4, "<14>Oct 16 14:39:24 sexpots-line1: Modem Command: AT&F1s0=0m0l1s48=7s36=5&W", 75, MSG_NOSIGNAL, NULL, 0) = 75
write(3, "A", 1) = 1
write(3, "T", 1) = 1
write(3, "&", 1) = 1
write(3, "F", 1) = 1
write(3, "1", 1) = 1
write(3, "s", 1) = 1
write(3, "0", 1) = 1
write(3, "=", 1) = 1
write(3, "0", 1) = 1
write(3, "m", 1) = 1
write(3, "0", 1) = 1
write(3, "l", 1) = 1
write(3, "1", 1) = 1
write(3, "s", 1) = 1
write(3, "4", 1) = 1
write(3, "8", 1) = 1
write(3, "=", 1) = 1
write(3, "7", 1) = 1
write(3, "s", 1) = 1
write(3, "3", 1) = 1
write(3, "6", 1) = 1
write(3, "=", 1) = 1
write(3, "5", 1) = 1
write(3, "&", 1) = 1
write(3, "W", 1) = 1
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=100000000}, 0x7ffef742a9b0) = 0
ioctl(3, TCFLSH, TCIFLUSH) = 0
write(3, "\r", 1) = 1
sendto(4, "<15>Oct 16 14:39:24 sexpots-line1: Waiting for Modem Response ...", 65, MSG_NOSIGNAL, NULL, 0) = 65
~~~
Then I get 60,000 lines of
~~~
read(3, 0x7ffef742a98f, 1) = -1 EAGAIN (Resource temporarily unavailable)
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, 0x7ffef742aa60) = 0
~~~
However, as we've seen the resource is (or should be) available.
Running through service, yet a different result:
~~~
root@wibble:/usr/local/etc# systemctl start sexpots-line1
Oct 16 14:44:10 wibble systemd[1]: Started sexpots-line1.service.
Oct 16 14:44:10 wibble sexpots-line1: Reading /usr/local/etc/sexpots-line1.ini Oct 16 14:44:10 wibble sexpots-line1: Synchronet Communications I/O Library for Linux v1.19
Oct 16 14:44:10 wibble sexpots-line1: Build Apr 26 2023 17:36:57 GCC 11.3.0
Oct 16 14:44:10 wibble sexpots-line1: TCP Host: endofthelinebbs.com
Oct 16 14:44:10 wibble sexpots-line1: TCP Port: 23
Oct 16 14:44:10 wibble sexpots-line1: Opening Communications Device (COM Port): /dev/ttyACM0
root@wibble:/usr/local/etc# Oct 16 14:44:10 wibble sexpots-line1: COM Port device handle: 3
Oct 16 14:44:10 wibble sexpots-line1: COM Port DTE rate: 0 bps
Oct 16 14:44:10 wibble sexpots-line1: Initializing modem:
Oct 16 14:44:10 wibble sexpots-line1: Modem Command: AT&F1s0=0m0l1s48=7s36=5&W Oct 16 14:44:10 wibble sexpots-line1: ERROR 11 sending modem command (AT&F1s0=0m0l1s48=7s36=5&W) on /dev/ttyACM0
Oct 16 14:44:10 wibble sexpots-line1: Retry #1: sending modem command (AT&F1s0=0m0l1s48=7s36=5&W) on /dev/ttyACM0
Oct 16 14:44:10 wibble sexpots-line1: Dropping DTR on /dev/ttyACM0
Oct 16 14:44:11 wibble sexpots-line1: Raising DTR on /dev/ttyACM0
Oct 16 14:44:11 wibble sexpots-line1: Modem Command: AT&F1s0=0m0l1s48=7s36=5&W Oct 16 14:44:11 wibble sexpots-line1: ERROR 11 sending modem command (AT&F1s0=0m0l1s48=7s36=5&W) on /dev/ttyACM0
Oct 16 14:44:11 wibble sexpots-line1: Retry #2: sending modem command (AT&F1s0=0m0l1s48=7s36=5&W) on /dev/ttyACM0
Oct 16 14:44:11 wibble sexpots-line1: Dropping DTR on /dev/ttyACM0
Oct 16 14:44:11 wibble sexpots-line1: Raising DTR on /dev/ttyACM0
Oct 16 14:44:11 wibble sexpots-line1: Modem Command: AT&F1s0=0m0l1s48=7s36=5&W Oct 16 14:44:11 wibble sexpots-line1: ERROR 11 sending modem command (AT&F1s0=0m0l1s48=7s36=5&W) on /dev/ttyACM0
Oct 16 14:44:11 wibble sexpots-line1: Modem command (AT&F1s0=0m0l1s48=7s36=5&W) failure on /dev/ttyACM0 (3 attempts)
Oct 16 14:44:11 wibble sexpots-line1: Cleaning up ...
Oct 16 14:44:11 wibble sexpots-line1: Done (handled 0 calls).
Oct 16 14:44:11 wibble sexpots[31739]: Synchronet External POTS Support v2.0-Linux Copyright 2023 Rob Swindell
Oct 16 14:44:11 wibble systemd[1]: sexpots-line1.service: Deactivated successfully.
~~~
So I'm at a bit of a loss as to what is happening here.
I run minicom with minicom -D /dev/ttyACM0
and then send the command
~~~
Welcome to minicom 2.8
OPTIONS: I18n
Port /dev/ttyACM0, 14:44:10
Press CTRL-A Z for help on special keys
AT&F1s0=0m0l1s48=7s36=5&W
OK
OK
~~~
Works fine.
--- SBBSecho 3.20-Linux
* Origin: Vertrauen - [vert/cvs/bbs].synchro.net (1:103/705)