ThomasHabets / ax25ms

This project is a set of AX.25 microservices, to be pluggable for any implementation.
Apache License 2.0
31 stars 0 forks source link

Errors when building #1

Closed isavitsky closed 2 years ago

isavitsky commented 2 years ago

Hello,

When trying to build the project there is an error that header file could not be found. Perhaps someone could look at the output and provide some insights on what's wrong with my setup?

Here is output from bootstrap.sh:

$ ./bootstrap.sh 
configure.ac:18: warning: Unknown LT_INIT option 'libtool'
configure.ac:18: warning: Unknown LT_INIT option 'libtool'
libtoolize: putting auxiliary files in '.'.
libtoolize: copying file './ltmain.sh'
libtoolize: Consider adding 'AC_CONFIG_MACRO_DIRS([m4])' to configure.ac,
libtoolize: and rerunning libtoolize and aclocal.
libtoolize: Consider adding '-I m4' to ACLOCAL_AMFLAGS in Makefile.am.
configure.ac:18: warning: Unknown LT_INIT option 'libtool'
configure.ac:5: warning: The macro `AC_CANONICAL_SYSTEM' is obsolete.
configure.ac:5: You should run autoupdate.
./lib/autoconf/general.m4:2081: AC_CANONICAL_SYSTEM is expanded from...
configure.ac:5: the top level
configure.ac:9: warning: The macro `AC_CONFIG_HEADER' is obsolete.
configure.ac:9: You should run autoupdate.
./lib/autoconf/status.m4:719: AC_CONFIG_HEADER is expanded from...
configure.ac:9: the top level
configure.ac:18: warning: The macro `AC_PROG_LIBTOOL' is obsolete.
configure.ac:18: You should run autoupdate.
aclocal.m4:121: AC_PROG_LIBTOOL is expanded from...
configure.ac:18: the top level
configure.ac:22: warning: The macro `AC_LANG_CPLUSPLUS' is obsolete.
configure.ac:22: You should run autoupdate.
./lib/autoconf/c.m4:262: AC_LANG_CPLUSPLUS is expanded from...
configure.ac:22: the top level
configure.ac:49: warning: The macro `AC_TYPE_SIGNAL' is obsolete.
configure.ac:49: You should run autoupdate.
./lib/autoconf/types.m4:776: AC_TYPE_SIGNAL is expanded from...
configure.ac:49: the top level
configure.ac:12: installing './compile'
configure.ac:5: installing './config.guess'
configure.ac:5: installing './config.sub'
configure.ac:7: installing './install-sh'
configure.ac:7: installing './missing'
Makefile.am: installing './depcomp'
parallel-tests: installing './test-driver'

Here is the output from configure:

$ ./configure
checking build system type... x86_64-pc-linux-gnu
checking host system type... x86_64-pc-linux-gnu
checking target system type... x86_64-pc-linux-gnu
checking for a BSD-compatible install... /usr/bin/install -c
checking whether build environment is sane... yes
checking for a race-free mkdir -p... /usr/bin/mkdir -p
checking for gawk... gawk
checking whether make sets $(MAKE)... yes
checking whether make supports nested variables... yes
checking whether to enable maintainer-specific portions of Makefiles... no
checking for gcc... gcc
checking whether the C compiler works... yes
checking for C compiler default output file name... a.out
checking for suffix of executables... 
checking whether we are cross compiling... no
checking for suffix of object files... o
checking whether the compiler supports GNU C... yes
checking whether gcc accepts -g... yes
checking for gcc option to enable C11 features... none needed
checking whether gcc understands -c and -o together... yes
checking whether make supports the include directive... yes (GNU style)
checking dependency style of gcc... gcc3
checking for g++... g++
checking whether the compiler supports GNU C++... yes
checking whether g++ accepts -g... yes
checking for g++ option to enable C++11 features... none needed
checking dependency style of g++... gcc3
checking whether make sets $(MAKE)... (cached) yes
checking how to print strings... printf
checking for a sed that does not truncate output... /usr/bin/sed
checking for grep that handles long lines and -e... /usr/bin/grep
checking for egrep... /usr/bin/grep -E
checking for fgrep... /usr/bin/grep -F
checking for ld used by gcc... /usr/bin/ld
checking if the linker (/usr/bin/ld) is GNU ld... yes
checking for BSD- or MS-compatible name lister (nm)... /usr/bin/nm -B
checking the name lister (/usr/bin/nm -B) interface... BSD nm
checking whether ln -s works... yes
checking the maximum length of command line arguments... 1572864
checking how to convert x86_64-pc-linux-gnu file names to x86_64-pc-linux-gnu format... func_convert_file_noop
checking how to convert x86_64-pc-linux-gnu file names to toolchain format... func_convert_file_noop
checking for /usr/bin/ld option to reload object files... -r
checking for objdump... objdump
checking how to recognize dependent libraries... pass_all
checking for dlltool... no
checking how to associate runtime and link libraries... printf %s\n
checking for ar... ar
checking for archiver @FILE support... @
checking for strip... strip
checking for ranlib... ranlib
checking command to parse /usr/bin/nm -B output from gcc object... ok
checking for sysroot... no
checking for a working dd... /usr/bin/dd
checking how to truncate binary pipes... /usr/bin/dd bs=4096 count=1
checking for mt... no
checking if : is a manifest tool... no
checking for stdio.h... yes
checking for stdlib.h... yes
checking for string.h... yes
checking for inttypes.h... yes
checking for stdint.h... yes
checking for strings.h... yes
checking for sys/stat.h... yes
checking for sys/types.h... yes
checking for unistd.h... yes
checking for dlfcn.h... yes
checking for objdir... .libs
checking if gcc supports -fno-rtti -fno-exceptions... no
checking for gcc option to produce PIC... -fPIC -DPIC
checking if gcc PIC flag -fPIC -DPIC works... yes
checking if gcc static flag -static works... yes
checking if gcc supports -c -o file.o... yes
checking if gcc supports -c -o file.o... (cached) yes
checking whether the gcc linker (/usr/bin/ld -m elf_x86_64) supports shared libraries... yes
checking whether -lc should be explicitly linked in... no
checking dynamic linker characteristics... GNU/Linux ld.so
checking how to hardcode library paths into programs... immediate
checking whether stripping libraries is possible... yes
checking if libtool supports shared libraries... yes
checking whether to build shared libraries... yes
checking whether to build static libraries... no
checking how to run the C++ preprocessor... g++ -E
checking for ld used by g++... /usr/bin/ld -m elf_x86_64
checking if the linker (/usr/bin/ld -m elf_x86_64) is GNU ld... yes
checking whether the g++ linker (/usr/bin/ld -m elf_x86_64) supports shared libraries... yes
checking for g++ option to produce PIC... -fPIC -DPIC
checking if g++ PIC flag -fPIC -DPIC works... yes
checking if g++ static flag -static works... yes
checking if g++ supports -c -o file.o... yes
checking if g++ supports -c -o file.o... (cached) yes
checking whether the g++ linker (/usr/bin/ld -m elf_x86_64) supports shared libraries... yes
checking dynamic linker characteristics... (cached) GNU/Linux ld.so
checking how to hardcode library paths into programs... immediate
checking for pkg-config... /usr/bin/pkg-config
checking pkg-config is at least version 0.9.0... yes
checking for protoc... protoc
checking for PROTOBUF... yes
checking for GRPCPP... yes
checking for signal.h... yes
checking for sys/socket.h... yes
checking for sys/types.h... (cached) yes
checking for grp.h... yes
checking for pwd.h... yes
checking for unistd.h... (cached) yes
checking for google/protobuf/stubs/logging.h... yes
checking for google/protobuf/stubs/common.h... yes
checking return type of signal handlers... void
checking that generated files are newer than configure... done
configure: creating ./config.status
config.status: creating Makefile
config.status: creating src/config.h
config.status: executing depfiles commands
config.status: executing libtool commands

  ax25ms version 0.01
  Prefix.........: /usr/local
  Debug Build....: 
  C++ Compiler...: g++ -g -O2  -pthread   -DNOMINMAX  -std=c++20 -g -Wall -pedantic 
  Linker.........: /usr/bin/ld -m elf_x86_64   -lprotobuf -lpthread  -lgrpc++ -lgrpc -laddress_sorting -lre2 -lupb -lcares -lz -lgpr -lssl -lcrypto -labsl_raw_hash_set -labsl_hashtablez_sampler -labsl_hash -labsl_city -labsl_low_level_hash -labsl_statusor -labsl_status -labsl_cord -labsl_cordz_info -labsl_cord_internal -labsl_cordz_functions -labsl_exponential_biased -labsl_cordz_handle -labsl_bad_optional_access -labsl_str_format_internal -labsl_synchronization -labsl_graphcycles_internal -labsl_stacktrace -labsl_symbolize -labsl_debugging_internal -labsl_demangle_internal -labsl_malloc_internal -labsl_time -labsl_civil_time -labsl_strings -labsl_strings_internal -lrt -labsl_base -labsl_spinlock_wait -labsl_int128 -labsl_throw_delegate -labsl_time_zone -labsl_bad_variant_access -labsl_raw_logging_internal -labsl_log_severity 

And finally the output from make:

$ make
depbase=`echo src/main.o | sed 's|[^/]*$|.deps/&|;s|\.o$||'`;\
g++ -DHAVE_CONFIG_H -I. -I./src  -I.   -g -O2  -pthread   -DNOMINMAX  -std=c++20 -g -Wall -pedantic -MT src/main.o -MD -MP -MF $depbase.Tpo -c -o src/main.o src/main.cc &&\
mv -f $depbase.Tpo $depbase.Po
depbase=`echo src/listen.o | sed 's|[^/]*$|.deps/&|;s|\.o$||'`;\
g++ -DHAVE_CONFIG_H -I. -I./src  -I.   -g -O2  -pthread   -DNOMINMAX  -std=c++20 -g -Wall -pedantic -MT src/listen.o -MD -MP -MF $depbase.Tpo -c -o src/listen.o src/listen.cc &&\
mv -f $depbase.Tpo $depbase.Po
In file included from src/listen.cc:22:
src/mic-e.h:16:10: fatal error: proto/gen/aprs.pb.h: No such file or directory
   16 | #include "proto/gen/aprs.pb.h"
      |          ^~~~~~~~~~~~~~~~~~~~~
compilation terminated.
make: *** [Makefile:1026: src/listen.o] Error 1

Apparently it's unable to generate the header files for some reason.

ThomasHabets commented 2 years ago

Generated protobuf files tend to not be compatible between versions, so best to regenerate them.

Run ./scripts/protogen to generate them.

isavitsky commented 2 years ago

Thanks! That helped.

ThomasHabets commented 2 years ago

I just added running that script to bootstrap.sh.

Please let me know how this code works out for you, or any other thoughts.

isavitsky commented 2 years ago

Hello Thomas,

As AX25_WINDOW is not available for the standard call utility I tried ax25ms with my TCP to SOCK_SEQPACKET proxy to a remote party which is running kernel AX.25 (linux-4.4, Debian 8) on Beaglebone Black and it failed to connect. It's starting the connection, but after remote replies it looses the connection and stops responding.

Next I wanted to compile ax25ms on beaglebone, but it runs arm7l Debian 8 which is pretty old and some packets aren't available. Particularly I was unable to find grpc. I tried to compile grpc on the beaglebone itself, but just the sources were about 1 GB in size. I managed to free some extra space on beaglebone, it was compiling the whole Sunday, and during the compilation it finally eaten all the disk space.

Then I thought I could comment-out AX25_WINDOW in call.c and recompile it from the ax25-util source on my laptop and try whether it will work with ax25ms afer that.

Meanwhile Manjaro on this laptop told me that it wants to update and after I updated I was unable to start ax25ms utilities because some *.so has upgraded it's version.

Now during ax25ms recompilation it throws another error:

/usr/bin/ld: src/serial.o: undefined reference to symbol 'pthread_setname_np@@GLIBC_2.12'
/usr/bin/ld: /usr/lib/libpthread.so.0: error adding symbols: DSO missing from command line
collect2: error: ld returned 1 exit status
make: *** [Makefile:974: serial] Error 1

I'll try to look at it tomorrow.

ThomasHabets commented 2 years ago

I've pushed a commit that ignores the application setting the AX25 options not yet supported. It should work fine without them. The options are for tweaking timers and windows. As long as the server doesn't mandate EXTSEQ it should work.

The DSO error sounds like it just needs a make clean && make.

Yeah, a downside to grpc is that it's pretty heavy to build the library. Maybe cross compiling is an option? I've not done much cross compiling though.

isavitsky commented 2 years ago

Hello Thomas,

I've pushed a commit that ignores the application setting the AX25 options not yet supported.

Thanks, I've been able to use a standard call utility. Now I can receive the Password: prompt from the remote system. But still unable to log in, because my I frames are zero-sized for some reason:

lora: fm UR5VIB to LORA1 ctl SABM- 18:26:34
lora: fm LORA1 to UR5VIB ctl UA- 18:26:34
lora: fm LORA1 to UR5VIB ctl I00+ pid=F0(Text) len 10 18:26:34
0000  50 61 73 73 77 6F 72 64 3A 20                    | Password: 
lora: fm UR5VIB to LORA1 ctl RR1- 18:26:35
lora: fm UR5VIB to LORA1 ctl I10^ pid=F0(Text) len 0 18:26:46
lora: fm LORA1 to UR5VIB ctl RR1v 18:26:49
lora: fm LORA1 to UR5VIB ctl I11+ pid=F0(Text) len 35 18:27:34
0000  0D 4C 6F 67 69 6E 20 74 69 6D 65 64 20 6F 75 74  | .Login timed out
0010  20 61 66 74 65 72 20 36 30 20 73 65 63 6F 6E 64  |  after 60 second
0020  73 2E 0D                                         | s..
lora: fm LORA1 to UR5VIB ctl DISC+ 18:27:34
lora: fm UR5VIB to LORA1 ctl RR2- 18:27:35
lora: fm LORA1 to UR5VIB ctl DM- 18:27:35
lora: fm UR5VIB to LORA1 ctl UA- 18:27:35

Where UR5VIB is my side with ax25sm and LORA1 is the remote (running linux kernel stack for AX.25).

Sometimes seqpacket throws an error:

Starting a new connection
packet {
  metadata {
    address {
      address: "LORA1"
    }
    connection_settings {
    }
    source_address {
      address: "UR5VIB"
    }
  }
}

Stopping timer t3
Stopping timer t1
Starting timer t1 with ms=6000
>>> State => AwaitingConnection
Stopping timer t1
Starting timer t1 with ms=3000
Stopping timer t1
Starting timer t1 with ms=3000
Stopping timer t1
  Sending data failed
Connect() exception: Sending data failed: Socket closed
./seqpacket: Exceptionbasic_string::at: __n (which is 3) >= this->size() (which is 3)

The DSO error sounds like it just needs a make clean && make.

Tried this and a clean git pull from the repository and still had that DSO error. Ended up with manually compiling specifying -lpthread at the end of line.

ThomasHabets commented 2 years ago

I've added check that should now add -lpthread. I thought I had, but clearly not.

And the zero length packets were due to the LD_PRELOAD not taking over enough library calls. I've now also fixed this, and axcall works for me.

I'm testing between ax25ms and the kernel implementation, and have not managed to see exceptions in seqpacket.

Could you share exactly which commands you run on the two sides? I think the most relevant is the axcall side and how you've set it up on the server side.

I should be able to debug it if I could reproduce it.

isavitsky commented 2 years ago

There is some progress. I've been able to connect and send some data but there is a problem when receiving packets larger than handful of bytes. Here is the output:

$ ./seqpacket -r localhost:12001 -l '[::]:12002'
Starting up a server
Server started
Starting a new connection
packet {
  metadata {
    address {
      address: "LORA1"
    }
    connection_settings {
    }
    source_address {
      address: "UR5VIB"
    }
  }
}

Stopping timer t3
Stopping timer t1
Starting timer t1 with ms=6000
>>> State => AwaitingConnection
DL-CONNECT confirm
Stopping timer t1
Stopping timer t3
>>> State => Connected
Got seqpacket frame of size 15
Stopping timer t1
Starting timer t3 with ms=300000
DL-DATA INDICATION
> Delivering data of size 10
Got seqpacket frame of size 26
Starting timer t1 with ms=3000
Stopping timer t3
Stopping timer t1
Starting timer t3 with ms=300000
DL-DATA INDICATION
> Delivering data of size 1
Got seqpacket frame of size 17
Stopping timer t1
Starting timer t3 with ms=300000
DL-DATA INDICATION
> Delivering data of size 61
Got seqpacket frame of size 77
DL ERROR: 14 (O: I frame exceeded maximum allowed length)
Stopping timer t3
Stopping timer t1
Starting timer t1 with ms=3000
>>> State => AwaitingConnection
Got seqpacket frame of size 272
Stopping reader
Connection ended
Connect() returning
Unknown connection src=LORA1 dst=UR5VIB
Unknown connection src=LORA1 dst=UR5VIB
Unknown connection src=LORA1 dst=UR5VIB
Unknown connection src=LORA1 dst=UR5VIB
./seqpacket: Exceptionbasic_string::at: __n (which is 3) >= this->size() (which is 3)

Trace from the remote side (password is omitted):

lora: fm UR5VIB to LORA1 ctl SABM- 19:07:42
lora: fm LORA1 to UR5VIB ctl UA- 19:07:42
lora: fm LORA1 to UR5VIB ctl I00+ pid=F0(Text) len 10 19:07:42
0000  50 61 73 73 77 6F 72 64 3A 20                    | Password: 
lora: fm UR5VIB to LORA1 ctl RR1- 19:07:42
lora: fm UR5VIB to LORA1 ctl I10^ pid=F0(Text) len 8 19:07:47
0000  xx xx xx xx xx xx xx 0D                          | xxxxxxx.
lora: fm LORA1 to UR5VIB ctl I11+ pid=F0(Text) len 1 19:07:47
0000  0D                                               | .
lora: fm UR5VIB to LORA1 ctl RR2- 19:07:47
lora: fm LORA1 to UR5VIB ctl I12+ pid=F0(Text) len 61 19:07:47
0000  4C 61 73 74 20 6C 6F 67 69 6E 3A 20 4D 6F 6E 20  | Last login: Mon 
0010  4A 61 6E 20 20 33 20 31 39 3A 34 36 3A 32 37 20  | Jan  3 19:46:27 
0020  55 54 43 20 32 30 32 32 20 66 72 6F 6D 20 41 58  | UTC 2022 from AX
0030  2E 32 35 20 6F 6E 20 70 74 73 2F 32 0D           | .25 on pts/2.
lora: fm UR5VIB to LORA1 ctl RR3- 19:07:47
lora: fm LORA1 to UR5VIB ctl I13+ pid=F0(Text) len 256 19:07:47
0000  4C 69 6E 75 78 20 6B 69 77 69 73 64 72 20 34 2E  | Linux kiwisdr 4.
0010  34 2E 31 35 35 2D 74 69 2D 72 31 35 30 20 23 31  | 4.155-ti-r150 #1
0020  20 53 4D 50 20 54 75 65 20 44 65 63 20 34 20 31  |  SMP Tue Dec 4 1
0030  39 3A 34 31 3A 30 33 20 55 54 43 20 32 30 31 38  | 9:41:03 UTC 2018
0040  20 61 72 6D 76 37 6C 0D 0D 54 68 65 20 70 72 6F  |  armv7l..The pro
0050  67 72 61 6D 73 20 69 6E 63 6C 75 64 65 64 20 77  | grams included w
0060  69 74 68 20 74 68 65 20 44 65 62 69 61 6E 20 47  | ith the Debian G
0070  4E 55 2F 4C 69 6E 75 78 20 73 79 73 74 65 6D 20  | NU/Linux system 
0080  61 72 65 20 66 72 65 65 20 73 6F 66 74 77 61 72  | are free softwar
0090  65 3B 0D 74 68 65 20 65 78 61 63 74 20 64 69 73  | e;.the exact dis
00A0  74 72 69 62 75 74 69 6F 6E 20 74 65 72 6D 73 20  | tribution terms 
00B0  66 6F 72 20 65 61 63 68 20 70 72 6F 67 72 61 6D  | for each program
00C0  20 61 72 65 20 64 65 73 63 72 69 62 65 64 20 69  |  are described i
00D0  6E 20 74 68 65 0D 69 6E 64 69 76 69 64 75 61 6C  | n the.individual
00E0  20 66 69 6C 65 73 20 69 6E 20 2F 75 73 72 2F 73  |  files in /usr/s
00F0  68 61 72 65 2F 64 6F 63 2F 2A 2F 63 6F 70 79 72  | hare/doc/*/copyr
lora: fm UR5VIB to LORA1 ctl SABM- 19:07:48
lora: fm LORA1 to UR5VIB ctl UA- 19:07:48
lora: fm LORA1 to UR5VIB ctl I00^ pid=F0(Text) len 256 19:07:48
0000  4C 69 6E 75 78 20 6B 69 77 69 73 64 72 20 34 2E  | Linux kiwisdr 4.
0010  34 2E 31 35 35 2D 74 69 2D 72 31 35 30 20 23 31  | 4.155-ti-r150 #1
0020  20 53 4D 50 20 54 75 65 20 44 65 63 20 34 20 31  |  SMP Tue Dec 4 1
0030  39 3A 34 31 3A 30 33 20 55 54 43 20 32 30 31 38  | 9:41:03 UTC 2018
0040  20 61 72 6D 76 37 6C 0D 0D 54 68 65 20 70 72 6F  |  armv7l..The pro
0050  67 72 61 6D 73 20 69 6E 63 6C 75 64 65 64 20 77  | grams included w
0060  69 74 68 20 74 68 65 20 44 65 62 69 61 6E 20 47  | ith the Debian G
0070  4E 55 2F 4C 69 6E 75 78 20 73 79 73 74 65 6D 20  | NU/Linux system 
0080  61 72 65 20 66 72 65 65 20 73 6F 66 74 77 61 72  | are free softwar
0090  65 3B 0D 74 68 65 20 65 78 61 63 74 20 64 69 73  | e;.the exact dis
00A0  74 72 69 62 75 74 69 6F 6E 20 74 65 72 6D 73 20  | tribution terms 
00B0  66 6F 72 20 65 61 63 68 20 70 72 6F 67 72 61 6D  | for each program
00C0  20 61 72 65 20 64 65 73 63 72 69 62 65 64 20 69  |  are described i
00D0  6E 20 74 68 65 0D 69 6E 64 69 76 69 64 75 61 6C  | n the.individual
00E0  20 66 69 6C 65 73 20 69 6E 20 2F 75 73 72 2F 73  |  files in /usr/s
00F0  68 61 72 65 2F 64 6F 63 2F 2A 2F 63 6F 70 79 72  | hare/doc/*/copyr
lora: fm LORA1 to UR5VIB ctl I01+ pid=F0(Text) len 120 19:07:48
0000  69 67 68 74 2E 0D 0D 44 65 62 69 61 6E 20 47 4E  | ight...Debian GN
0010  55 2F 4C 69 6E 75 78 20 63 6F 6D 65 73 20 77 69  | U/Linux comes wi
0020  74 68 20 41 42 53 4F 4C 55 54 45 4C 59 20 4E 4F  | th ABSOLUTELY NO
0030  20 57 41 52 52 41 4E 54 59 2C 20 74 6F 20 74 68  |  WARRANTY, to th
0040  65 20 65 78 74 65 6E 74 0D 70 65 72 6D 69 74 74  | e extent.permitt
0050  65 64 20 62 79 20 61 70 70 6C 69 63 61 62 6C 65  | ed by applicable
0060  20 6C 61 77 2E 0D 75 72 35 76 69 62 40 6B 69 77  |  law..ur5vib@kiw
0070  69 73 64 72 3A 7E 24 20                          | isdr:~$ 
lora: fm LORA1 to UR5VIB ctl RR0+ 19:07:55
lora: fm LORA1 to UR5VIB ctl RR0+ 19:08:10
lora: fm LORA1 to UR5VIB ctl RR0+ 19:08:32
lora: fm LORA1 to UR5VIB ctl RR0+ 19:09:01
lora: fm LORA1 to UR5VIB ctl RR0+ 19:09:38
lora: fm LORA1 to UR5VIB ctl RR0+ 19:10:22
lora: fm LORA1 to UR5VIB ctl RR0+ 19:11:14
lora: fm LORA1 to UR5VIB ctl RR0+ 19:12:12
lora: fm LORA1 to UR5VIB ctl RR0+ 19:13:19

After that I looked at the code and found that the amount of data is limited in src/seqpacket_con.h:

 unsigned int n1 = 200; // Max number of octets in the information field of a frame.

I increased it to 65535. That helped, but not for too long:

lora: fm UR5VIB to LORA1 ctl SABM- 19:56:47
lora: fm LORA1 to UR5VIB ctl UA- 19:56:47
lora: fm LORA1 to UR5VIB ctl I00+ pid=F0(Text) len 10 19:56:48
0000  50 61 73 73 77 6F 72 64 3A 20                    | Password: 
lora: fm UR5VIB to LORA1 ctl RR1- 19:56:48
lora: fm UR5VIB to LORA1 ctl I10^ pid=F0(Text) len 8 19:57:06
0000  xx xx xx xx xx xx xx 0D                          | xxxxxxx.
lora: fm LORA1 to UR5VIB ctl I11+ pid=F0(Text) len 1 19:57:06
0000  0D                                               | .
lora: fm UR5VIB to LORA1 ctl RR2- 19:57:06
lora: fm LORA1 to UR5VIB ctl I12+ pid=F0(Text) len 61 19:57:06
0000  4C 61 73 74 20 6C 6F 67 69 6E 3A 20 54 75 65 20  | Last login: Tue 
0010  4A 61 6E 20 20 34 20 31 39 3A 35 35 3A 31 38 20  | Jan  4 19:55:18 
0020  55 54 43 20 32 30 32 32 20 66 72 6F 6D 20 41 58  | UTC 2022 from AX
0030  2E 32 35 20 6F 6E 20 70 74 73 2F 32 0D           | .25 on pts/2.
lora: fm UR5VIB to LORA1 ctl RR3- 19:57:06
lora: fm LORA1 to UR5VIB ctl I13+ pid=F0(Text) len 256 19:57:06
0000  4C 69 6E 75 78 20 6B 69 77 69 73 64 72 20 34 2E  | Linux kiwisdr 4.
0010  34 2E 31 35 35 2D 74 69 2D 72 31 35 30 20 23 31  | 4.155-ti-r150 #1
0020  20 53 4D 50 20 54 75 65 20 44 65 63 20 34 20 31  |  SMP Tue Dec 4 1
0030  39 3A 34 31 3A 30 33 20 55 54 43 20 32 30 31 38  | 9:41:03 UTC 2018
0040  20 61 72 6D 76 37 6C 0D 0D 54 68 65 20 70 72 6F  |  armv7l..The pro
0050  67 72 61 6D 73 20 69 6E 63 6C 75 64 65 64 20 77  | grams included w
0060  69 74 68 20 74 68 65 20 44 65 62 69 61 6E 20 47  | ith the Debian G
0070  4E 55 2F 4C 69 6E 75 78 20 73 79 73 74 65 6D 20  | NU/Linux system 
0080  61 72 65 20 66 72 65 65 20 73 6F 66 74 77 61 72  | are free softwar
0090  65 3B 0D 74 68 65 20 65 78 61 63 74 20 64 69 73  | e;.the exact dis
00A0  74 72 69 62 75 74 69 6F 6E 20 74 65 72 6D 73 20  | tribution terms 
00B0  66 6F 72 20 65 61 63 68 20 70 72 6F 67 72 61 6D  | for each program
00C0  20 61 72 65 20 64 65 73 63 72 69 62 65 64 20 69  |  are described i
00D0  6E 20 74 68 65 0D 69 6E 64 69 76 69 64 75 61 6C  | n the.individual
00E0  20 66 69 6C 65 73 20 69 6E 20 2F 75 73 72 2F 73  |  files in /usr/s
00F0  68 61 72 65 2F 64 6F 63 2F 2A 2F 63 6F 70 79 72  | hare/doc/*/copyr
lora: fm UR5VIB to LORA1 ctl RR4- 19:57:07
lora: fm LORA1 to UR5VIB ctl I14+ pid=F0(Text) len 120 19:57:07
0000  69 67 68 74 2E 0D 0D 44 65 62 69 61 6E 20 47 4E  | ight...Debian GN
0010  55 2F 4C 69 6E 75 78 20 63 6F 6D 65 73 20 77 69  | U/Linux comes wi
0020  74 68 20 41 42 53 4F 4C 55 54 45 4C 59 20 4E 4F  | th ABSOLUTELY NO
0030  20 57 41 52 52 41 4E 54 59 2C 20 74 6F 20 74 68  |  WARRANTY, to th
0040  65 20 65 78 74 65 6E 74 0D 70 65 72 6D 69 74 74  | e extent.permitt
0050  65 64 20 62 79 20 61 70 70 6C 69 63 61 62 6C 65  | ed by applicable
0060  20 6C 61 77 2E 0D 75 72 35 76 69 62 40 6B 69 77  |  law..ur5vib@kiw
0070  69 73 64 72 3A 7E 24 20                          | isdr:~$ 
lora: fm LORA1 to UR5VIB ctl RR1+ 19:57:14
lora: fm LORA1 to UR5VIB ctl RR1+ 19:57:27
lora: fm LORA1 to UR5VIB ctl RR1+ 19:57:47
lora: fm LORA1 to UR5VIB ctl RR1+ 19:58:14
lora: fm LORA1 to UR5VIB ctl RR1+ 19:58:47

After I13+ and RR4- frames seqpacket stops responding where the last lines of serial are:

Injecting with size 272
  Added to queue
  Sending to client
Sending packet of size 18
c0 00 98 9e a4 82 62 40 60 aa a4 6a ac 92 84 e1 91 c0 
Packet sent
Injecting with size 178
  Added to queue
  Sending to client
Injecting with size 15
  Added to queue
  Sending to client
Stream stop
Injecting with size 15
  Dead entry
Injecting with size 15
Injecting with size 15
Injecting with size 15
ThomasHabets commented 2 years ago

Ah yes, for large packets DL ERROR: 14 (O: I frame exceeded maximum allowed length) is the key (hard to find in the verbose output, though).

65536 bytes would take about 7 and a half minutes to send at 1200bps, but yeah it depends what you have set as max in the other end.

So you're using axcall to dial into something, right? How did you set up the server side, so that I can more easily try to reproduce it?

What were the last lines of seqpacket when it stops responding?

isavitsky commented 2 years ago

As far as I can see in the spec they specify default maximum is 256, not 65535:

6.7.2.1. Maximum Number of Octets in an I Field (N1)
The default maximum number of octets allowed in the I field is 256

I should have looked into it before, but I don't believe there is an overflow somewhere. But this needs an extra check. Nevertheless as we can see from the traces, the remote party never sent more than 256 octets in one packet.

So you're using axcall to dial into something, right? How did you set up the server side

Exactly. The 'server' side is based on BeagleBone Black board and the setup is straightforward: /etc/rc.local:

/usr/sbin/kissattach /dev/ttyUSB0 lora
/usr/sbin/ax25d

/etc/ax25/axports:

lora    LORA1           115200  940     1       LoRa

/etc/ax25/ax25d.conf:

[lora]
NOCALL * * * * * * L
ur5vib 1 * * * * * * root /usr/sbin/axspawn axspawn %u +

What were the last lines of seqpacket when it stops responding?

I'll check that later this evening.

isavitsky commented 2 years ago

What were the last lines of seqpacket when it stops responding?

That's interesting, I'm unable to reproduce this issue now. I'm pretty sure that my setup hasn't changed since yesterday. I'll continue my shenanigans to see if there any chance to hang it up.

isavitsky commented 2 years ago

Unfortunately, that was the last time it was connecting. I transferred about 100 KB during that session without any problem. But all subsequent sessions were total failure for unknown reason. I did screen capture here: https://youtu.be/5LQVxo74uxQ This time seqpacket exited when I killed call in another window.

ThomasHabets commented 2 years ago

If you're still interested in this I've fixed two issues with timers for ACKs and retransmissions not kicking off as they should. It may work better for you now.

isavitsky commented 2 years ago

Hello Thomas,

Thanks for the update. Just pulled and recompiled the new version. But something is wrong there. I was unable to establish the connection. I'll try to check more closely on the weekend. Here are some screenshots.

isavitsky commented 2 years ago

Screenshot_20220217_220227 Screenshot_20220217_220251 Screenshot_20220217_220307

ThomasHabets commented 2 years ago

I think I've set up similar as your config and it seems to work here.

Server

Client

It seems to work reliably for me. Well, you're right I should bump the max frame size, and I now have (commit just pushed).

The serial->RPC output from your screenshot is weird. Why would it be reading all those zeroes? The RPC->Serial looks good, but it appear not not be receiving any packet at all from the TNC.

That's actually good, because it looks like the whole path from axcall to the serial port looks good, but on the receive side there's a problem between the TNC and the serial service. And that serial-rpc gateway is the simplest component.

What TNC is it?

If while serial is running you run stty -F /dev/ttyUSB0 (or with -a too), does it still have the settings you expect your TNC to have?

I am assuming that the TNC speaks KISS?

Does it mandate that a CRC is used?

ThomasHabets commented 2 years ago

I've not tried running ax25d/axspawn under ax25ms yet. I will, but not tonight as it's getting late here.

I see you did get a successfull connection once, that seems to immediately fail?

When you test it may be good between tests to kill seqpacket and restart it, in case a previous connection attempt left some state. It shouldn't, but I fixed a couple of bugs where it did.

ThomasHabets commented 2 years ago

Ok, I've experimented with ax25d under ax25ms now. In short: it doesn't work yet. Client side seems to work fine, but I need to think a bit about how to best map the POSIX socket APIs to an RPC API, to make listen/select/accept be transparent on the server side through the LD_PRELOAD.

I've opened #2 for this.

isavitsky commented 2 years ago

Hello Thomas,

The LoRa modem that I built on top of ESP32 and RIOT-OS is not really a KISS device. It's acting more like a simplex serial extender between two linux TNCs a few miles apart one from the another. Despite LoRa has built-in CRC capabilities, sometimes it receives noise. The modem puts whichever it thinks a data packet (garbage) directly to the serial line. Another thing I always keep forgetting of is weird behavior of ROIT-OS with random multiplication of characters on the serial line. (I think it's a RIOT-OS problem and I need to fix it.) Perhaps these factors are responsible for trains of zeroes in the serial line that I failed to recognise the last time. Because garbage in the serial line could occur any time, I think maybe it's needed to extra check the incoming data for sanity to prevent those exceptions and exits of seqpacket.

I just repeated the same steps as I did last time and now the call-ing the remote is working. There is also a problem where I left the opened connection for a long time and it's broke as soon as I started to sending data: Serial:

ax25ms 2022-02-20 21:59:28 RPC -> Serial (size 18) :c0 00 98 9e a4 82 62 40 60 aa a4 6a ac 92 84 e1 b1 c0 
ax25ms 2022-02-20 22:01:17 Read thread failed (restarting): INVALID Escape
ax25ms 2022-02-20 22:04:29 Serial -> RPC (size 15): aa a4 6a ac 92 84 e0 98 9e a4 82 62 40 61 31 
ax25ms 2022-02-20 22:04:29 RPC -> Serial (size 18) :c0 00 98 9e a4 82 62 40 60 aa a4 6a ac 92 84 e1 b1 c0 
ax25ms 2022-02-20 22:09:30 Serial -> RPC (size 178): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
ax25ms 2022-02-20 22:09:30 Serial -> RPC (size 15): aa a4 6a ac 92 84 e0 98 9e a4 82 62 40 61 31 
ax25ms 2022-02-20 22:09:30 Stream stop
ax25ms 2022-02-20 22:09:36 Serial -> RPC (size 15): aa a4 6a ac 92 84 e0 98 9e a4 82 62 40 61 31 
ax25ms 2022-02-20 22:09:36   Dead entry
ax25ms 2022-02-20 22:09:48 Serial -> RPC (size 15): aa a4 6a ac 92 84 e0 98 9e a4 82 62 40 61 31 
ax25ms 2022-02-20 22:10:06 Serial -> RPC (size 15): aa a4 6a ac 92 84 e0 98 9e a4 82 62 40 61 31 
ax25ms 2022-02-20 22:10:31 Serial -> RPC (size 15): aa a4 6a ac 92 84 e0 98 9e a4 82 62 40 61 31 
ax25ms 2022-02-20 22:11:01 Serial -> RPC (size 15): aa a4 6a ac 92 84 e0 98 9e a4 82 62 40 61 31 
ax25ms 2022-02-20 22:11:37 Serial -> RPC (size 15): aa a4 6a ac 92 84 e0 98 9e a4 82 62 40 61 31 
ax25ms 2022-02-20 22:12:20 Serial -> RPC (size 15): aa a4 6a ac 92 84 e0 98 9e a4 82 62 40 61 31 
ax25ms 2022-02-20 22:13:08 Serial -> RPC (size 15): aa a4 6a ac 92 84 e0 98 9e a4 82 62 40 61 31 
ax25ms 2022-02-20 22:14:02 Serial -> RPC (size 15): aa a4 6a ac 92 84 e0 98 9e a4 82 62 40 61 31 
ax25ms 2022-02-20 22:15:03 Serial -> RPC (size 15): aa a4 6a ac 92 84 e0 98 9e a4 82 62 40 61 31 
ax25ms 2022-02-20 22:15:39 RPC -> Serial (size 25) :c0 00 98 9e a4 82 62 40 e0 aa a4 6a ac 92 84 61 a2 f0 70 73 20 61 78 0d c0 
ax25ms 2022-02-20 22:15:39 Serial -> RPC (size 272): aa a4 6a ac 92 84 e0 98 9e a4 82 62 40 61 5a f0 70 73 20 61 78 0d 20 20 50 49 44 20 54 54 59 20 20 20 20 20 20 53 54 41 54 20 20 20 54 49 4d 45 20 43 4f 4d 4d 41 4e 44 0d 20 20 20 20 31 20 3f 20 20 20 20 20 20 20 20 53 73 20 20 20 20 20 31 3a 32 35 20 2f 73 62 69 6e 2f 69 6e 69 74 0d 20 20 20 20 32 20 3f 20 20 20 20 20 20 20 20 53 20 20 20 20 20 20 30 3a 30 30 20 5b 6b 74 68 72 65 61 64 64 5d 0d 20 20 20 20 33 20 3f 20 20 20 20 20 20 20 20 53 20 20 20 20 20 20 30 3a 31 33 20 5b 6b 73 6f 66 74 69 72 71 64 2f 30 5d 0d 20 20 20 20 35 20 3f 20 20 20 20 20 20 20 20 53 3c 20 20 20 20 20 30 3a 30 30 20 5b 6b 77 6f 72 6b 65 72 2f 30 3a 30 48 5d 0d 20 20 20 20 37 20 3f 20 20 20 20 20 20 20 20 53 20 20 20 20 20 20 30 3a 32 35 20 5b 72 63 75 5f 73 63 68 65 64 5d 0d 20 20 20 20 38 20 3f 20 20 20 20 20 20 20 20 53 20 
ax25ms 2022-02-20 22:15:42 RPC -> Serial (size 18) :c0 00 98 9e a4 82 62 40 e0 aa a4 6a ac 92 84 61 b1 c0 
ax25ms 2022-02-20 22:15:42 Serial -> RPC (size 15): aa a4 6a ac 92 84 60 98 9e a4 82 62 40 e1 51 
ax25ms 2022-02-20 22:16:09 Serial -> RPC (size 15): aa a4 6a ac 92 84 60 98 9e a4 82 62 40 e1 1f 

Seqpacket:

ax25ms 2022-02-20 21:59:28 1 Stopping timer t1
ax25ms 2022-02-20 21:59:28 1 Starting timer t3 with ms=300000
ax25ms 2022-02-20 22:04:28 1 Stopping timer t3
ax25ms 2022-02-20 22:04:28 1 ERROR: unhandled T3 in state Connected
ax25ms 2022-02-20 22:04:29 1 Stopping timer t1
ax25ms 2022-02-20 22:04:29 1 Starting timer t3 with ms=300000
ax25ms 2022-02-20 22:09:29 1 Stopping timer t3
ax25ms 2022-02-20 22:09:29 1 ERROR: unhandled T3 in state Connected
ax25ms 2022-02-20 22:15:39 1 Starting timer t1 with ms=3000
ax25ms 2022-02-20 22:15:39 1 Stopping timer t3
ax25ms 2022-02-20 22:15:42 1 Stopping timer t1
ax25ms 2022-02-20 22:15:42 1 Connected::timer1_tick()
ax25ms 2022-02-20 22:15:42 1 Starting timer t1 with ms=3000
ax25ms 2022-02-20 22:15:42 1 >>> State => TimerRecovery
ax25ms 2022-02-20 22:15:45 1 Stopping timer t1
ax25ms 2022-02-20 22:15:45 1 TimerRecovery::timer1_tick()
ax25ms 2022-02-20 22:15:45   Sending data failed
terminate called after throwing an instance of 'std::runtime_error'
  what():  Sending data failed: Socket closed
Aborted (core dumped)

Thanks again for all your efforts!