Error parsing encapsulated message

[jasmith86]

When using rtlamr and rtlamr-collect, I get the following JSON unmarshaling error for any output from rtlamr. I redacted the ID and CHECKSUM in the output and also tee'd the pipe to see what exactly rtlamr-collect was receiving (though I get the same errors with or without tee).

$  rtlamr | tee /dev/pts/1 | rtlamr-collect

09:52:32.620336 flags.go:111: Environment variable "RTLAMR_FILTERID" overrides flag "filterid" with "1053xxxx"
09:52:32.620471 flags.go:111: Environment variable "RTLAMR_FORMAT" overrides flag "format" with "json"
09:52:32.620829 decode.go:45: CenterFreq: 912600155
09:52:32.620842 decode.go:46: SampleRate: 2359296
09:52:32.620849 decode.go:47: DataRate: 32768
09:52:32.620856 decode.go:48: ChipLength: 72
09:52:32.620862 decode.go:49: PreambleSymbols: 21
09:52:32.620868 decode.go:50: PreambleLength: 3024
09:52:32.620874 decode.go:51: PacketSymbols: 96
09:52:32.620880 decode.go:52: PacketLength: 13824
09:52:32.620888 decode.go:59: Protocols: scm
09:52:32.620895 decode.go:60: Preambles: 111110010101001100000
09:52:32.620902 main.go:111: GainCount: 29
09:52:32.621530 main.go:353: connecting to "rtluser"@"http://localhost:8086/"
{"Time":"2019-08-19T09:53:56.069061986-04:00","Offset":0,"Length":0,"Message":{"ID":1053xxxx,"Type":12,"TamperPhy":3,"TamperEnc":0,"Consumption":5587,"ChecksumVal":24xxx}}
09:53:56.069664 main.go:398: json unmarshal: json: Unmarshal(nil)

To get a bit more info, I also made this patch to print out a bit more info:

Index: main.go
IDEA additional info:
Subsystem: com.intellij.openapi.diff.impl.patch.CharsetEP
<+>UTF-8
===================================================================
--- main.go	(date 1555814264000)
+++ main.go	(date 1566226362704)
@@ -396,6 +396,9 @@
 		err = json.Unmarshal(logMsg.Message, msg)
 		if err != nil {
 			log.Println(errors.Wrap(err, "json unmarshal"))
+			log.Printf("logMsg: %+v\n", logMsg)
+			log.Printf("logMsg.Message: %v\n", string(	logMsg.Message))
+			log.Printf("msg: %+v\n", msg)
 			continue
 		}
 

That produced the following output:

$ rtlamr | tee /dev/pts/1 | rtlamr-collect                                

10:55:11.559172 main.go:353: connecting to "rtluser"@"http://localhost:8086/"
10:55:11.579869 flags.go:111: Environment variable "RTLAMR_FORMAT" overrides flag "format" with "json"
10:55:11.580731 decode.go:45: CenterFreq: 912600155
10:55:11.580763 decode.go:46: SampleRate: 2359296
10:55:11.580767 decode.go:47: DataRate: 32768
10:55:11.580772 decode.go:48: ChipLength: 72
10:55:11.580776 decode.go:49: PreambleSymbols: 21
10:55:11.580784 decode.go:50: PreambleLength: 3024
10:55:11.580789 decode.go:51: PacketSymbols: 96
10:55:11.580793 decode.go:52: PacketLength: 13824
10:55:11.580805 decode.go:59: Protocols: scm
10:55:11.580810 decode.go:60: Preambles: 111110010101001100000
10:55:11.580826 main.go:111: GainCount: 29
{"Time":"2019-08-19T10:55:16.092272358-04:00","Offset":0,"Length":0,"Message":{"ID":3372xxxx,"Type":12,"TamperPhy":0,"TamperEnc":0,"Consumption":143548,"ChecksumVal":29xxx}}
10:55:16.093033 main.go:398: json unmarshal: json: Unmarshal(nil)
10:55:16.093146 main.go:399: logMsg: {Time:2019-08-19 10:55:16.092272358 -0400 EDT Type:}
10:55:16.093201 main.go:400: logMsg.Message: {"ID":3372xxxx,"Type":12,"TamperPhy":0,"TamperEnc":0,"Consumption":143548,"ChecksumVal":29xxx}
10:55:16.093232 main.go:401: msg: <nil>

Let me know if there is any other info that would help

[jasmith86]

Did a little more digging and it looks like logMsg.Type doesn't have a value.

index fef931d..8694029 100644
--- a/main.go
+++ b/main.go
@@ -390,12 +390,17 @@ func main() {
 			msg = new(IDM)
 		case "R900", "R900BCD":
 			msg = new(R900)
+		default:
+			log.Printf("logMsg.Type not set. %+v\n", logMsg)
 		}
 
 		// Parse the encapsulated message.
 		err = json.Unmarshal(logMsg.Message, msg)
 		if err != nil {
 			log.Println(errors.Wrap(err, "json unmarshal"))
+			log.Printf("logMsg: %+v\n", logMsg)
+			log.Printf("logMsg.Message: %v\n", string(logMsg.Message))
+			log.Printf("msg: %T %+v\n", msg, msg)
 			continue
 		}
 

The output is then:

$ rtlamr | tee /dev/pts/1 | rtlamr-collect
11:44:18.240748 flags.go:111: Environment variable "RTLAMR_FORMAT" overrides flag "format" with "json"
11:44:18.241134 decode.go:45: CenterFreq: 912600155
11:44:18.241148 decode.go:46: SampleRate: 2359296
11:44:18.241153 decode.go:47: DataRate: 32768
11:44:18.241157 decode.go:48: ChipLength: 72
11:44:18.241161 decode.go:49: PreambleSymbols: 21
11:44:18.241167 decode.go:50: PreambleLength: 3024
11:44:18.241172 decode.go:51: PacketSymbols: 96
11:44:18.241176 decode.go:52: PacketLength: 13824
11:44:18.241180 decode.go:59: Protocols: scm
11:44:18.241186 decode.go:60: Preambles: 111110010101001100000
11:44:18.241192 main.go:111: GainCount: 29
11:44:18.242200 main.go:353: connecting to "rtluser"@"http://localhost:8086/"
{"Time":"2019-08-19T11:44:34.307117087-04:00","Offset":0,"Length":0,"Message":{"ID":6581xxxx,"Type":12,"TamperPhy":3,"TamperEnc":0,"Consumption":185077,"ChecksumVal":53xxx}}
11:44:34.308239 main.go:394: logMsg.Type not set. {Time:2019-08-19 11:44:34.307117087 -0400 EDT Type:}
11:44:34.308312 main.go:400: json unmarshal: json: Unmarshal(nil)
11:44:34.308332 main.go:401: logMsg: {Time:2019-08-19 11:44:34.307117087 -0400 EDT Type:}
11:44:34.308358 main.go:402: logMsg.Message: {"ID":6581xxxx,"Type":12,"TamperPhy":3,"TamperEnc":0,"Consumption":185077,"ChecksumVal":53xxx}
11:44:34.308371 main.go:403: msg: <nil> <nil>

[bemasher]

Ah yeah, you're using incompatible versions of rtlamr and rtlamr-collect. The lastest flavor of rtlamr-collect expects there to be a "Type" field in each message and the latest version of rtlamr provides that field, but I've not yet made a tagged release including those changes. The release of go modules has been somewhat turbulent for this project.

Try:

go get -v github.com/bemasher/rtlamr@latest
go get -v github.com/bemasher/rtlamr-collect@latest

[peterhuson]

I just collected the latest versions using

go get -v github.com/bemasher/rtlamr@latest
go get -v github.com/bemasher/rtlamr-collect@latest

And received an infinite stream of Unmarshal(nil):

/ $ /home/pi/go/bin/rtlamr -msgtype=scm,scm+,idm,netidm -format=json | /home/pi/go/bin/rtlamr-collect
02:10:53.574854 decode.go:45: CenterFreq: 912600155
02:10:53.575536 decode.go:46: SampleRate: 2359296
02:10:53.575648 decode.go:47: DataRate: 32768
02:10:53.575746 decode.go:48: ChipLength: 72
02:10:53.575843 decode.go:49: PreambleSymbols: 32
02:10:53.575939 decode.go:50: PreambleLength: 4608
02:10:53.576034 decode.go:51: PacketSymbols: 736
02:10:53.576130 decode.go:52: PacketLength: 105984
02:10:53.576252 decode.go:59: Protocols: scm,scm+,idm,netidm
02:10:53.576418 decode.go:60: Preambles: 0001011010100011,01010101010101010001011010100011,111110010101001100000
02:10:53.576528 main.go:111: GainCount: 29
02:10:53.575070 main.go:355: connecting to "power"@"http://localhost:8086"
02:10:54.458244 main.go:400: json unmarshal: json: Unmarshal(nil)
02:11:00.488564 main.go:400: json unmarshal: json: Unmarshal(nil)

However, getting them normally seemed to work fine:

/ $ go get -v github.com/bemasher/rtlamr
/ $ go get -v github.com/bemasher/rtlamr-collect
/ $ /home/pi/go/bin/rtlamr -msgtype=scm,scm+,idm,netidm -format=json | /home/pi/go/bin/rtlamr-collect
02:22:18.158155 decode.go:45: CenterFreq: 912600155
02:22:18.158797 decode.go:46: SampleRate: 2359296
02:22:18.158852 decode.go:47: DataRate: 32768
02:22:18.158900 decode.go:48: ChipLength: 72
02:22:18.158946 decode.go:49: PreambleSymbols: 32
02:22:18.158995 decode.go:50: PreambleLength: 4608
02:22:18.159042 decode.go:51: PacketSymbols: 736
02:22:18.159090 decode.go:52: PacketLength: 105984
02:22:18.159155 decode.go:59: Protocols: scm,scm+,idm,netidm
02:22:18.159245 decode.go:60: Preambles: 111110010101001100000,0001011010100011,01010101010101010001011010100011
02:22:18.159302 main.go:119: GainCount: 29
02:22:18.159884 main.go:355: connecting to "power"@"http://localhost:8086"
02:22:19.980280 main.go:431: rtlamr,endpoint_id=105_____,endpoint_type=12,msg_type=cumulative,protocol=SCM consumption=4996i 157_______________________
02:22:23.851680 main.go:431: rtlamr,endpoint_id=150_____,endpoint_type=12,msg_type=cumulative,protocol=SCM consumption=29428i 157_______________________
...

[bemasher]

Turns out @latest will pull the latest tagged commit. I will need to make a new release to correct this. In the meantime, I would recommend cloning the repositories for rtlamr and rtlamr-collect directly with git.