g4klx / ircDDBGateway

The ircDDB Gateway for D-Star
GNU General Public License v2.0
61 stars 41 forks source link

Repeatedly message "Error returned from read()" in log file #70

Closed reinerwill closed 2 years ago

reinerwill commented 2 years ago

Hi, I've installed the current ircDDBGateway package on our CentOS 7 gateway DB0HRF, already running ICOM G3. On an old G2 installation I found the trick of Hansjuergen DL5DI to replace the script gwstart.sh with a dummy loop script. This seems to work so far. So G3 is runniing the database for registration only, while dplus and dsm is stopped. But short after the start "systemctrl start ircddbgatewayd.service" I see messages "Error returned from read()" raising in the log file, about 190 time every second. On my radio I hear the messages like "Not connected", but can't connect to any reflector for test.

grep "00:06:06: Error" /var/log/opendv/ircDDBGateway-2022-01-03.log
...
E: 2022-01-03 00:06:06: Error returned from read()
E: 2022-01-03 00:06:06: Error returned from read()
E: 2022-01-03 00:06:06: Error returned from read()
...
[root@dstar dsgwd]# grep "00:06:06: Error" /var/log/opendv/ircDDBGateway-2022-01-03.log | wc -l
192
[root@dstar dsgwd]# grep "00:06:07: Error" /var/log/opendv/ircDDBGateway-2022-01-03.log | wc -l
191
[root@dstar dsgwd]# grep "00:06:08: Error" /var/log/opendv/ircDDBGateway-2022-01-03.log | wc -l
192

I can't figure out the root cause of this problem. Any idea how to debug this? I'm thinking of strace or so, but have not really an idea where to start. Please help!

73, Reiner DH9FAX

reinerwill commented 2 years ago

Hi,

Nobody can help me, as it seems, but I still hope someone can. In the meantime I have the idea that it could be a rights issue. In this version the daemon is started as user opendv. To what groups do this user need to belong to? The current config is like this:

[root@dstar ~]# grep opendv /etc/group
dialout:x:18:opendv
audio:x:63:opendv
opendv:x:993:

Is there any group missing maybe?

73, Reiner DH9FAX

reinerwill commented 2 years ago

Hi,

There was an idea if the permission for the log file and folder are wrong, but they are good, logs are written. In the beginning of the log everything looks good, but after a while it continuously shows this error:

M: 2022-01-13 21:10:04: Starting ircDDB Gateway daemon - 20200621 - DEBUGM: 2022-01-13 21:10:04: Opened connection to the APRS Gateway
M: 2022-01-13 21:10:05: Initial sequence number from the RP2C is 1
M: 2022-01-13 21:10:05: Connected 'MSG' to DB0HRF   using file - /home/opendv/message.dvtool
M: 2022-01-13 21:10:05: Connected 'WX' to DB0HRF   using file - /home/opendv/weather.dvtool
M: 2022-01-13 21:10:05: Version text set to "ircDDB GW - 20200621"
M: 2022-01-13 21:10:05: Adding DB0HRF A to the cache as a local repeater
M: 2022-01-13 21:10:05: Connected 'MSG' to DB0HRF   using file - /home/opendv/message.dvtool
M: 2022-01-13 21:10:05: Connected 'WX' to DB0HRF   using file - /home/opendv/weather.dvtool
M: 2022-01-13 21:10:05: Version text set to "ircDDB GW - 20200621"
E: 2022-01-13 21:10:05: Cannot bind the TCP server address, err=98
M: 2022-01-13 21:10:05: Adding DB0HRF AD to the cache as a local repeater
M: 2022-01-13 21:10:05: Connected 'MSG' to DB0HRF   using file - /home/opendv/message.dvtool
M: 2022-01-13 21:10:05: Connected 'WX' to DB0HRF   using file - /home/opendv/weather.dvtool
M: 2022-01-13 21:10:05: Version text set to "ircDDB GW - 20200621"
E: 2022-01-13 21:10:05: Cannot bind the TCP server address, err=98
M: 2022-01-13 21:10:05: Adding DB0HRF B to the cache as a local repeater
M: 2022-01-13 21:10:05: File /home/opendv/CCS_Hosts.txt not readable
M: 2022-01-13 21:10:05: Reading /usr/share/opendv/CCS_Hosts.txt
M: 2022-01-13 21:10:05: Downloading XLX reflector list from http://xlxapi.rlx.lu/api.php?do=GetXLXDMRMaster
M: 2022-01-13 21:10:05: Starting the D-RATS Server thread for DB0HRF  
M: 2022-01-13 21:10:05: Starting the Icom Controller thread
M: 2022-01-13 21:10:05: Truncating /var/log/opendv/Links.log
M: 2022-01-13 21:10:05: Truncating /var/log/opendv/STARnet.log
M: 2022-01-13 21:10:05: Allocated UDP ports 30001-30007 to DExtra
M: 2022-01-13 21:10:05: Allocated UDP ports 20001-20007 to D-Plus
M: 2022-01-13 21:10:05: Allocated UDP ports 30051-30057 to DCS
M: 2022-01-13 21:10:05: Starting the ircDDB Gateway thread
M: 2022-01-13 21:10:05: Reading /tmp/XLX_Hosts_jS8N7i
M: 2022-01-13 21:10:05: Loaded 626 of 626 XLX reflectors from /tmp/XLX_Hosts_jS8N7i
E: 2022-01-13 21:10:05: Cannot find address for host xlx735.openquad.net
M: 2022-01-13 21:10:05: Locking W4LCO    to 208.89.76.92
E: 2022-01-13 21:10:05: Cannot find address for host w5dra.gw.ircddb.net
M: 2022-01-13 21:10:05: Loaded 1381 of 1383 D-Plus reflectors from /usr/share/opendv/DPlus_Hosts.txt
E: 2022-01-13 21:10:06: Cannot find address for host xrf500.org
E: 2022-01-13 21:10:07: Cannot find address for host xrf851.rsdt.de
M: 2022-01-13 21:10:07: Loaded 650 of 652 DExtra reflectors from /usr/share/opendv/DExtra_Hosts.txt
M: 2022-01-13 21:10:07: Locking DCS005   to 87.117.229.51
M: 2022-01-13 21:10:07: Locking DCS006   to 198.133.14.38
M: 2022-01-13 21:10:07: Locking DCS010   to 85.197.129.86
M: 2022-01-13 21:10:07: Locking DCS012   to 194.38.140.205
E: 2022-01-13 21:10:07: Cannot find address for host dcs034.xreflector.net
E: 2022-01-13 21:10:07: Cannot find address for host xlx735.openquad.net
E: 2022-01-13 21:10:07: Cannot find address for host xrf915.ddns.net
M: 2022-01-13 21:10:07: Loaded 1260 of 1263 DCS reflectors from /usr/share/opendv/DCS_Hosts.txt
M: 2022-01-13 21:10:07: File /home/opendv/de_DE.ambe not readable
M: 2022-01-13 21:10:07: Reading /usr/share/opendv/de_DE.ambe
M: 2022-01-13 21:10:07: File /home/opendv/de_DE.indx not readable
M: 2022-01-13 21:10:07: Reading /usr/share/opendv/de_DE.indx
E: 2022-01-13 21:10:07: TUNSETIFF ioctl failed, closing the tap device
M: 2022-01-13 21:10:07: CCS: Opening UDP port 30062 for DB0HRF A
M: 2022-01-13 21:10:07: CCS: Opening UDP port 30064 for DB0HRF B
M: 2022-01-13 21:10:07: DCS: DCS001     5.252.227.231
M: 2022-01-13 21:10:07: DCS: DCS002     185.228.139.209
M: 2022-01-13 21:10:07: DCS: DCS003     176.10.105.254
M: 2022-01-13 21:10:07: DCS: DCS004     77.243.52.148
M: 2022-01-13 21:10:07: DCS: DCS005     87.117.229.51
M: 2022-01-13 21:10:07: DCS: DCS006     198.133.14.38
M: 2022-01-13 21:10:07: DCS: DCS007     44.137.42.27
M: 2022-01-13 21:10:07: DCS: DCS008     87.106.84.53
M: 2022-01-13 21:10:07: DCS: DCS009     89.185.97.35
M: 2022-01-13 21:10:07: DCS: DCS010     85.197.129.86
M: 2022-01-13 21:10:07: DCS: DCS011     81.95.126.168
M: 2022-01-13 21:10:07: DCS: DCS012     194.38.140.205
M: 2022-01-13 21:10:07: DCS: DCS013     195.159.104.200
M: 2022-01-13 21:10:07: DCS: DCS014     52.63.223.130
M: 2022-01-13 21:10:07: DCS: DCS015     194.59.205.228
M: 2022-01-13 21:10:07: DCS: DCS016     87.106.3.249
M: 2022-01-13 21:10:07: DCS: DCS017     201.62.48.60
M: 2022-01-13 21:10:07: DCS: DCS018     161.97.73.43
M: 2022-01-13 21:10:07: DCS: DCS019     31.7.247.58
M: 2022-01-13 21:10:07: DCS: DCS021     5.175.14.43
M: 2022-01-13 21:10:07: DCS: DCS022     157.7.142.179
M: 2022-01-13 21:10:07: DCS: DCS023     77.85.192.94
M: 2022-01-13 21:10:07: DCS: DCS024     75.151.47.163
M: 2022-01-13 21:10:07: DCS: DCS025     87.229.30.227
M: 2022-01-13 21:10:07: DCS: DCS026     209.42.149.140
M: 2022-01-13 21:10:07: DCS: DCS027     128.199.57.19
M: 2022-01-13 21:10:07: DCS: DCS028     125.63.61.20
M: 2022-01-13 21:10:07: DCS: DCS031     213.202.229.40
M: 2022-01-13 21:10:07: DCS: DCS032     158.64.26.140
M: 2022-01-13 21:10:07: DCS: DCS033     152.228.170.16
M: 2022-01-13 21:10:07: DCS: DCS262     87.139.70.67
M: 2022-01-13 21:10:07: DCS: DCS844     137.226.79.122
M: 2022-01-13 21:10:07: DCS: DCS945     213.202.229.40
M: 2022-01-13 21:10:07: DCS: DCS111     213.202.229.40
M: 2022-01-13 21:10:07: Registered with dns.xreflector.net using callsign DB0HRF
M: 2022-01-13 21:10:07: Loaded 34 DCS reflectors from dns.xreflector.net
E: 2022-01-13 21:10:07: Error returned from read()
M: 2022-01-13 21:10:07: Starting the D-Plus Authenticator thread
E: 2022-01-13 21:10:07: Error returned from read()
M: 2022-01-13 21:10:07: Starting the Callsign Server thread
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()
E: 2022-01-13 21:10:07: Error returned from read()

73, Reiner DH9FAX

reinerwill commented 2 years ago

It's very sad that this amazing project is not monitored, and no one can help. I'm still facing continuously "Error returned from read()" messages in the log. The system is not usable. You can't transmit neither link to any reflector. In the meantime I tried also on a Debian server beside the CentOS I tried before. Same problem.

I'm really sad! :-( Reiner, DH9FAX

g4klx commented 2 years ago

Please ask on the OpenDB@groups.io group, that is where support occurs.

reinerwill commented 2 years ago

Hi Jonathan,

I didn't found OpenDB group related to amateur radio. I guess you meant OpenDV, but I've already placed my issue there two month ago with no luck. I will try again...

Best 73 Reiner DH9FAX

IvanGirderboot commented 2 months ago

@reinerwill I ran into this issue today and traced it down in the code. You may or may not care, but I'm posting it here for posterity.

My guess is that you're not running this as root, which is good practice. However, the binary needs root-level access in order to manipulate the networking stack, including being able to create interfaces for the data module (if you have one defined).

You have two choice here:

To add the capability, run sudo setcap 'cap_net_admin=ep' /path/to/ircddbgateway-binary and restart the process.

Hope this helps someone in the future!

Note: A trailing space in the module name (A vs A) will trick the code into thinking a data module is in the system (normally named AD) and attempt to create the data device,