Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

main.go:90: Error connecting to spectrum server: dial tcp 127.0.0.1:1234: connect: connection refused #141

Closed
erikpendragon opened this issue Jun 9, 2022 · 11 comments
Closed

main.go:90: Error connecting to spectrum server: dial tcp 127.0.0.1:1234: connect: connection refused #141

erikpendragon opened this issue Jun 9, 2022 · 11 comments
Labels
bug Something isn't working

Comments

@erikpendragon
Copy link

Any time I have to restart or stop/start the home assistant add-on I get a connection refused error.

Default config other then listen mode set to true

restarting host computer will allow it to come back up

I think it is because there are two PIDs and restart only kills one of them.

[2022-06-09 11:41:25] Using "/data/options.json" config file
[2022-06-09 11:41:25] Fetching default MQTT configuration from http://supervisor/services/mqtt
[2022-06-09 11:41:25] Starting in LISTEN ONLY Mode...
[2022-06-09 11:41:25] Using "/data/options.json" config file
[2022-06-09 11:41:25] Fetching default MQTT configuration from http://supervisor/services/mqtt
[2022-06-09 11:41:25] Configured MQTT sender:
[2022-06-09 11:41:25] > hostname => core-mosquitto
[2022-06-09 11:41:25] > port => 1883
[2022-06-09 11:41:25] > username => addons
[2022-06-09 11:41:25] > client_id => rtlamr2mqtt
[2022-06-09 11:41:25] > base_topic => rtlamr
[2022-06-09 11:41:25] > availability_topic => rtlamr/status
[2022-06-09 11:41:25] > tls => None
[2022-06-09 11:41:25] Starting rtl_tcp with /usr/bin/rtl_tcp
[2022-06-09 11:41:27] Starting rtlamr with ['/usr/bin/rtlamr', '-msgtype=all', '-format=json']
[2022-06-09 11:41:27] You should see all utility meters after this line:
[2022-06-09 11:41:27] 11:41:27.829757 main.go:90: Error connecting to spectrum server: dial tcp 127.0.0.1:1234: connect: connection refused
[2022-06-09 11:41:27] rcvr.Connect
[2022-06-09 11:41:27] main.(*Receiver).NewReceiver
[2022-06-09 11:41:27] /go/pkg/mod/github.com/bemasher/rtlamr@v0.9.3/main.go:90
[2022-06-09 11:41:27] main.main
[2022-06-09 11:41:27] /go/pkg/mod/github.com/bemasher/rtlamr@v0.9.3/main.go:313
[2022-06-09 11:41:27] runtime.main
[2022-06-09 11:41:27] /usr/local/go/src/runtime/proc.go:250
[2022-06-09 11:41:27] runtime.goexit
[2022-06-09 11:41:27] /usr/local/go/src/runtime/asm_amd64.s:1571
@erikpendragon
Copy link
Author

if I restart the host computer, the system seems to time out after 8 min, not sure if this is a new issue or related.

[2022-06-09 11:50:54] Using "/data/options.json" config file
[2022-06-09 11:50:54] Fetching default MQTT configuration from http://supervisor/services/mqtt
[2022-06-09 11:50:54] Starting in LISTEN ONLY Mode...
[2022-06-09 11:50:54] Using "/data/options.json" config file
[2022-06-09 11:50:54] Fetching default MQTT configuration from http://supervisor/services/mqtt
[2022-06-09 11:50:54] Configured MQTT sender:
[2022-06-09 11:50:54] > hostname => core-mosquitto
[2022-06-09 11:50:54] > port => 1883
[2022-06-09 11:50:54] > username => addons
[2022-06-09 11:50:54] > client_id => rtlamr2mqtt
[2022-06-09 11:50:54] > base_topic => rtlamr
[2022-06-09 11:50:54] > availability_topic => rtlamr/status
[2022-06-09 11:50:54] > tls => None
[2022-06-09 11:50:54] Starting rtl_tcp with /usr/bin/rtl_tcp
[2022-06-09 11:50:56] Starting rtlamr with ['/usr/bin/rtlamr', '-msgtype=all', '-format=json']
[2022-06-09 11:50:56] You should see all utility meters after this line:
[2022-06-09 11:50:56] 11:50:56.294182 decode.go:45: CenterFreq: 912380000
[2022-06-09 11:50:56] 11:50:56.294863 decode.go:46: SampleRate: 2359296
[2022-06-09 11:50:56] 11:50:56.294877 decode.go:47: DataRate: 32768
[2022-06-09 11:50:56] 11:50:56.294884 decode.go:48: ChipLength: 72
[2022-06-09 11:50:56] 11:50:56.294890 decode.go:49: PreambleSymbols: 32
[2022-06-09 11:50:56] 11:50:56.294896 decode.go:50: PreambleLength: 4608
[2022-06-09 11:50:56] 11:50:56.294902 decode.go:51: PacketSymbols: 736
[2022-06-09 11:50:56] 11:50:56.294908 decode.go:52: PacketLength: 105984
[2022-06-09 11:50:56] 11:50:56.294918 decode.go:59: Protocols: scm,scm+,idm,r900
[2022-06-09 11:50:56] 11:50:56.294927 decode.go:60: Preambles: 111110010101001100000,0001011010100011,01010101010101010001011010100011,00000000000000001110010101100100
[2022-06-09 11:50:56] 11:50:56.294941 main.go:124: GainCount: 29
[2022-06-09 11:58:39] 11:58:39.669107 main.go:343: Receiver context cancelled.
[2022-06-09 11:58:39] 11:58:39.669305 main.go:320: read tcp 127.0.0.1:51094->127.0.0.1:1234: i/o timeout
[2022-06-09 11:58:39] io.ReadFull
[2022-06-09 11:58:39] main.(*Receiver).Run.func2
[2022-06-09 11:58:39] /go/pkg/mod/github.com/bemasher/rtlamr@v0.9.3/main.go:181
[2022-06-09 11:58:39] runtime.goexit
[2022-06-09 11:58:39] /usr/local/go/src/runtime/asm_amd64.s:1571

@allangood
Copy link
Owner

I think you are running with this same problem her: #98
It may be related to your USB device. As suggested, a powered USB hub would help with that.

Regards.

@ibejtm
Copy link

ibejtm commented Jun 13, 2022

Well, I've been having a similar issue for the last week. I don't have my radio on a powered hub, but it has been working fine for several month now at this point. The message that stood out to me is the "io.ReadFull". Is there a possibility that the new value can't overwrite the old one? My setup always works for the first scan after a restart, but then fails every time after that. I've tried it with the device ID set to "single" or by specifying the hardware ID:

[2022-06-13 15:37:10] Using "/data/options.json" config file
[2022-06-13 15:37:10] Fetching default MQTT configuration from http://supervisor/services/mqtt
[2022-06-13 15:37:10] RTLAMR2MQTT Starting...
[2022-06-13 15:37:11] RTL SDR Device 0bda:2838 found on USB port 001:004 - Index: 0
[2022-06-13 15:37:11] Configured MQTT sender:
[2022-06-13 15:37:11] > hostname
[2022-06-13 15:37:11] > port
[2022-06-13 15:37:11] > username
[2022-06-13 15:37:11] > client_id => rtlamr2mqtt
[2022-06-13 15:37:11] > base_topic => rtlamr
[2022-06-13 15:37:11] > availability_topic => rtlamr/status
[2022-06-13 15:37:11] > tls => None
[2022-06-13 15:37:11] Reseting USB device: /dev/bus/usb/001/004
[2022-06-13 15:37:11] Reset sucessful.
[2022-06-13 15:37:11] Sending message to MQTT:
[2022-06-13 15:37:11] > topic => rtlamr/status
[2022-06-13 15:37:11] > payload => online
[2022-06-13 15:37:11] > retain => True
[2022-06-13 15:37:11] Trying to start RTL_TCP: /usr/bin/rtl_tcp -d 0 -s 2048000
[2022-06-13 15:37:11] RTL_TCP started with PID 10
[2022-06-13 15:37:16] RTL_TCP is ready to receive connections!
[2022-06-13 15:37:16] Trying to start RTLAMR: /usr/bin/rtlamr -msgtype=scm,r900 -format=json -filterid=9374579,700091634 -unique=true
[2022-06-13 15:37:16] RTLAMR started with PID 15
[2022-06-13 15:37:16] 15:37:16.477098 decode.go:45: CenterFreq: 912600155
[2022-06-13 15:37:16] 15:37:16.477499 decode.go:46: SampleRate: 2359296
[2022-06-13 15:37:16] 15:37:16.477520 decode.go:47: DataRate: 32768
[2022-06-13 15:37:16] 15:37:16.477530 decode.go:48: ChipLength: 72
[2022-06-13 15:37:16] 15:37:16.477540 decode.go:49: PreambleSymbols: 32
[2022-06-13 15:37:16] 15:37:16.477549 decode.go:50: PreambleLength: 4608
[2022-06-13 15:37:16] 15:37:16.477558 decode.go:51: PacketSymbols: 116
[2022-06-13 15:37:16] 15:37:16.477567 decode.go:52: PacketLength: 16704
[2022-06-13 15:37:16] 15:37:16.477582 decode.go:59: Protocols: r900,scm
[2022-06-13 15:37:16] 15:37:16.477623 decode.go:60: Preambles: 00000000000000001110010101100100,111110010101001100000
[2022-06-13 15:37:16] 15:37:16.477672 main.go:124: GainCount: 29
[2022-06-13 15:38:37] {"Time":"2022-06-13T15:38:37.340871327-04:00","Offset":0,"Length":0,"Type":"SCM","Message":{"ID":9374579,"Type":12,"TamperPhy":2,"TamperEnc":0,"Consumption":38855,"ChecksumVal":57675}}
[2022-06-13 15:38:37] Meter "9374579" - Consumption 038855.. Sending value to MQTT.
[2022-06-13 15:38:37] Sending MQTT autodiscovery payload to Home Assistant...
[2022-06-13 15:38:37] Sending message to MQTT:
[2022-06-13 15:38:37] > topic => homeassistant/sensor/rtlamr/gas_meter/config
[2022-06-13 15:38:37] > payload => {"name": "gas_meter", "unique_id": "9374579", "unit_of_measurement": "ft\u00b3", "icon": "mdi:gas-cylinder", "availability_topic": "rtlamr/status", "state_class": "total_increasing", "state_topic": "rtlamr/9374579/state", "json_attributes_topic": "rtlamr/9374579/attributes", "device_class": "gas"}
[2022-06-13 15:38:37] > qos => 1
[2022-06-13 15:38:37] > retain => True
[2022-06-13 15:38:37] Sending message to MQTT:
[2022-06-13 15:38:37] > topic => rtlamr/9374579/attributes
[2022-06-13 15:38:37] > payload => {"Message Type": "SCM", "ID": 9374579, "Type": 12, "TamperPhy": 2, "TamperEnc": 0, "Consumption": 38855, "ChecksumVal": 57675}
[2022-06-13 15:38:37] > retain => True
[2022-06-13 15:38:37] Sending message to MQTT:
[2022-06-13 15:38:37] > topic => rtlamr/9374579/state
[2022-06-13 15:38:37] > payload => 038855.
[2022-06-13 15:38:37] > retain => True
[2022-06-13 15:39:04] {"Time":"2022-06-13T15:39:04.045782195-04:00","Offset":0,"Length":0,"Type":"R900","Message":{"ID":700091634,"Unkn1":131,"NoUse":33,"BackFlow":0,"Consumption":948869,"Unkn3":0,"Leak":0,"LeakNow":0}}
[2022-06-13 15:39:04] Meter "700091634" - Consumption 94.8869. Sending value to MQTT.
[2022-06-13 15:39:04] Sending MQTT autodiscovery payload to Home Assistant...
[2022-06-13 15:39:04] Sending message to MQTT:
[2022-06-13 15:39:04] > topic => homeassistant/sensor/rtlamr/water_meter/config
[2022-06-13 15:39:04] > payload => {"name": "water_meter", "unique_id": "700091634", "unit_of_measurement": "CCF", "icon": "mdi:water-boiler", "availability_topic": "rtlamr/status", "state_class": "total_increasing", "state_topic": "rtlamr/700091634/state", "json_attributes_topic": "rtlamr/700091634/attributes"}
[2022-06-13 15:39:04] > qos => 1
[2022-06-13 15:39:04] > retain => True
[2022-06-13 15:39:04] Sending message to MQTT:
[2022-06-13 15:39:04] > topic => rtlamr/700091634/attributes
[2022-06-13 15:39:04] > payload => {"Message Type": "R900", "ID": 700091634, "Unkn1": 131, "NoUse": 33, "BackFlow": 0, "Consumption": 948869, "Unkn3": 0, "Leak": 0, "LeakNow": 0}
[2022-06-13 15:39:04] > retain => True
[2022-06-13 15:39:04] Sending message to MQTT:
[2022-06-13 15:39:04] > topic => rtlamr/700091634/state
[2022-06-13 15:39:04] > payload => 94.8869
[2022-06-13 15:39:04] > retain => True
[2022-06-13 15:39:04] Sleep_for defined, time to sleep!
[2022-06-13 15:39:04] Terminating all subprocess...
[2022-06-13 15:39:04] Kill process called.
[2022-06-13 15:39:04] Killing RTLAMR...
[2022-06-13 15:39:04] Killed in the first attempt.
[2022-06-13 15:39:04] Sleeping for 300 seconds, see you later...

...

[2022-06-13 15:44:04] Reseting USB device: /dev/bus/usb/001/004
[2022-06-13 15:44:04] Reset sucessful.
[2022-06-13 15:44:04] Sending message to MQTT:
[2022-06-13 15:44:04] > topic => rtlamr/status
[2022-06-13 15:44:04] > payload => online
[2022-06-13 15:44:04] > retain => True
[2022-06-13 15:44:04] Trying to start RTLAMR: /usr/bin/rtlamr -msgtype=scm,r900 -format=json -filterid=9374579,700091634 -unique=true
[2022-06-13 15:44:04] RTLAMR started with PID 27
[2022-06-13 15:44:04] 15:44:04.529068 decode.go:45: CenterFreq: 912380000
[2022-06-13 15:44:04] 15:44:04.529359 decode.go:46: SampleRate: 2359296
[2022-06-13 15:44:04] 15:44:04.529378 decode.go:47: DataRate: 32768
[2022-06-13 15:44:04] 15:44:04.529389 decode.go:48: ChipLength: 72
[2022-06-13 15:44:04] 15:44:04.529399 decode.go:49: PreambleSymbols: 32
[2022-06-13 15:44:04] 15:44:04.529408 decode.go:50: PreambleLength: 4608
[2022-06-13 15:44:04] 15:44:04.529418 decode.go:51: PacketSymbols: 116
[2022-06-13 15:44:04] 15:44:04.529428 decode.go:52: PacketLength: 16704
[2022-06-13 15:44:04] 15:44:04.529445 decode.go:59: Protocols: scm,r900
[2022-06-13 15:44:04] 15:44:04.529458 decode.go:60: Preambles: 111110010101001100000,00000000000000001110010101100100
[2022-06-13 15:44:04] 15:44:04.529469 main.go:124: GainCount: 29
[2022-06-13 15:44:09] 15:44:09.535534 main.go:343: Receiver context cancelled.
[2022-06-13 15:44:09] 15:44:09.536714 main.go:320: read tcp 127.0.0.1:41148->127.0.0.1:1234: i/o timeout
[2022-06-13 15:44:09] io.ReadFull
[2022-06-13 15:44:09] main.(*Receiver).Run.func2
[2022-06-13 15:44:09] /go/pkg/mod/github.com/bemasher/rtlamr@v0.9.3/main.go:181
[2022-06-13 15:44:09] runtime.goexit
[2022-06-13 15:44:09] /usr/local/go/src/runtime/asm_arm64.s:1263
[2022-06-13 15:44:09] Sleep_for defined, time to sleep!
[2022-06-13 15:44:09] Terminating all subprocess...
[2022-06-13 15:44:09] Kill process called.
[2022-06-13 15:44:09] Killing RTLAMR...
[2022-06-13 15:44:09] Killed in the first attempt.
[2022-06-13 15:44:09] Sleeping for 300 seconds, see you later...

Any suggestions? I don't mind getting a powered hub, but I'm surprised that it is only just now an issue.

@ibejtm
Copy link

ibejtm commented Jun 13, 2022

After reading a little more of the closed issues, it sounds like this is a powered USB hub issue. There are at least two other closed issues that refer to the io.ReadFull issue. Sorry for the trouble!

@allangood
Copy link
Owner

This issue will be close now.

@erikpendragon
Copy link
Author

my powered hub came in today, I am still getting the same issue.

[2022-06-14 14:35:46] Using "/data/options.json" config file
[2022-06-14 14:35:46] Fetching default MQTT configuration from http://supervisor/services/mqtt
[2022-06-14 14:35:46] Starting in LISTEN ONLY Mode...
[2022-06-14 14:35:46] Using "/data/options.json" config file
[2022-06-14 14:35:46] Fetching default MQTT configuration from http://supervisor/services/mqtt
[2022-06-14 14:35:46] Configured MQTT sender:
[2022-06-14 14:35:46] > hostname => core-mosquitto
[2022-06-14 14:35:46] > port => 1883
[2022-06-14 14:35:46] > username => addons
[2022-06-14 14:35:46] > client_id => rtlamr2mqtt
[2022-06-14 14:35:46] > base_topic => rtlamr
[2022-06-14 14:35:46] > availability_topic => rtlamr/status
[2022-06-14 14:35:46] > tls => None
[2022-06-14 14:35:46] Starting rtl_tcp with /usr/bin/rtl_tcp
[2022-06-14 14:35:48] Starting rtlamr with ['/usr/bin/rtlamr', '-msgtype=all', '-format=json']
[2022-06-14 14:35:48] You should see all utility meters after this line:
[2022-06-14 14:35:48] 14:35:48.997783 main.go:90: Error connecting to spectrum server: dial tcp 127.0.0.1:1234: connect: connection refused
[2022-06-14 14:35:48] rcvr.Connect
[2022-06-14 14:35:48] main.(*Receiver).NewReceiver
[2022-06-14 14:35:48] /go/pkg/mod/github.com/bemasher/rtlamr@v0.9.3/main.go:90
[2022-06-14 14:35:48] main.main
[2022-06-14 14:35:48] /go/pkg/mod/github.com/bemasher/rtlamr@v0.9.3/main.go:313
[2022-06-14 14:35:48] runtime.main
[2022-06-14 14:35:48] /usr/local/go/src/runtime/proc.go:250
[2022-06-14 14:35:48] runtime.goexit
[2022-06-14 14:35:48] /usr/local/go/src/runtime/asm_amd64.s:1571

@allangood
Copy link
Owner

You seems to be running in listen_only mode, try to run in normal mode.

@erikpendragon
Copy link
Author

I am in listen only mode, I don't know the ID of my meters, I can try normal mode just for troubleshooting though.

@erikpendragon
Copy link
Author

I am also still getting the io read full error (listen only mode)

[2022-06-14 15:06:06] Using "/data/options.json" config file
[2022-06-14 15:06:06] Fetching default MQTT configuration from http://supervisor/services/mqtt
[2022-06-14 15:06:06] Starting in LISTEN ONLY Mode...
[2022-06-14 15:06:06] Using "/data/options.json" config file
[2022-06-14 15:06:06] Fetching default MQTT configuration from http://supervisor/services/mqtt
[2022-06-14 15:06:06] Configured MQTT sender:
[2022-06-14 15:06:06] > hostname => core-mosquitto
[2022-06-14 15:06:06] > port => 1883
[2022-06-14 15:06:06] > username => addons
[2022-06-14 15:06:06] > client_id => rtlamr2mqtt
[2022-06-14 15:06:06] > base_topic => rtlamr
[2022-06-14 15:06:06] > availability_topic => rtlamr/status
[2022-06-14 15:06:06] > tls => None
[2022-06-14 15:06:06] Starting rtl_tcp with /usr/bin/rtl_tcp
[2022-06-14 15:06:08] Starting rtlamr with ['/usr/bin/rtlamr', '-msgtype=all', '-format=json']
[2022-06-14 15:06:08] You should see all utility meters after this line:
[2022-06-14 15:06:08] 15:06:08.474991 decode.go:45: CenterFreq: 912380000
[2022-06-14 15:06:08] 15:06:08.475666 decode.go:46: SampleRate: 2359296
[2022-06-14 15:06:08] 15:06:08.475677 decode.go:47: DataRate: 32768
[2022-06-14 15:06:08] 15:06:08.475682 decode.go:48: ChipLength: 72
[2022-06-14 15:06:08] 15:06:08.475686 decode.go:49: PreambleSymbols: 32
[2022-06-14 15:06:08] 15:06:08.475689 decode.go:50: PreambleLength: 4608
[2022-06-14 15:06:08] 15:06:08.475692 decode.go:51: PacketSymbols: 736
[2022-06-14 15:06:08] 15:06:08.475695 decode.go:52: PacketLength: 105984
[2022-06-14 15:06:08] 15:06:08.475702 decode.go:59: Protocols: scm,scm+,idm,r900
[2022-06-14 15:06:08] 15:06:08.475707 decode.go:60: Preambles: 111110010101001100000,0001011010100011,01010101010101010001011010100011,00000000000000001110010101100100
[2022-06-14 15:06:08] 15:06:08.475716 main.go:124: GainCount: 29
[2022-06-14 15:14:03] 15:14:03.053966 main.go:343: Receiver context cancelled.
[2022-06-14 15:14:03] 15:14:03.054248 main.go:320: read tcp 127.0.0.1:51228->127.0.0.1:1234: i/o timeout
[2022-06-14 15:14:03] io.ReadFull
[2022-06-14 15:14:03] main.(*Receiver).Run.func2
[2022-06-14 15:14:03] /go/pkg/mod/github.com/bemasher/rtlamr@v0.9.3/main.go:181
[2022-06-14 15:14:03] runtime.goexit
[2022-06-14 15:14:03] /usr/local/go/src/runtime/asm_amd64.s:1571

@allangood
Copy link
Owner

Ok. I am reopening this issue and try to recreate the problem and troubleshoot.

Thank you for your feedback!

@allangood allangood reopened this Jun 14, 2022
@allangood allangood mentioned this issue Jun 14, 2022
Merged
allangood added a commit that referenced this issue Jun 14, 2022
@allangood
Merge pull request #146 from allangood/dev
b40b499 
Fix for #141
@allangood
Copy link
Owner

I think I've found the problem. RTL_TCP was left open/running after the "kill call".

In the output (with problem) no RTL_TCP kill attempt:

[2022-06-13 15:44:09] Sleep_for defined, time to sleep!
[2022-06-13 15:44:09] Terminating all subprocess...
[2022-06-13 15:44:09] Kill process called.
[2022-06-13 15:44:09] Killing RTLAMR...
[2022-06-13 15:44:09] Killed in the first attempt.
[2022-06-13 15:44:09] Sleeping for 300 seconds, see you later...

This is the (with the fix) output:

[2022-06-14 16:21:23] Sleep_for defined, time to sleep!
[2022-06-14 16:21:23] Terminating all subprocess...
[2022-06-14 16:21:23] Kill process called.
[2022-06-14 16:21:23] Killing RTL_TCP...
[2022-06-14 16:21:28] Killed.
[2022-06-14 16:21:28] Killing RTLAMR...
[2022-06-14 16:21:28] Killed in the first attempt.
[2022-06-14 16:21:28] Sleeping for 300 seconds, see you later...

@allangood allangood added bug Something isn't working and removed not a bug labels Jun 15, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@allangood @erikpendragon @ibejtm