GRC Script Error Code 1

[raspyweather]

Hey,
I'm using a raspberry pi 2, have adjusted all files and the script is giving out the correct azimuth and elevation of the satellite, but it does not create any files. I executed it with and without sudo without noticeable difference. That's what I got in the logs so far:

2018-11-04 18:13:54,965 - root - DEBUG - start GRC script
2018-11-04 18:13:55,068 - root - DEBUG - started /FTP/meteor/MeteorRpiReceiver/GRC/METEOR_M2_v04_noGUI.py with PID:4726 ['/usr/bin/python', '/FTP/meteor/MeteorRpiReceiver/GRC/METEOR_M2_v04_noGUI.py'] started at 2018-11-04 18:13:55.068271
2018-11-04 18:25:46,513 - root - DEBUG - stopping GRC script
2018-11-04 18:25:46,585 - root - DEBUG - GRC script ended with return code: 1
2018-11-04 18:26:06,620 - root - DEBUG - decoding: no recent file was found
2018-11-04 18:26:06,622 - root - DEBUG - no e-mail sent as there was no decoded image
2018-11-04 18:26:06,623 - root - DEBUG - all done, start over for next pass
2018-11-04 18:26:06,625 - root - DEBUG - trying TLE download...
2018-11-04 18:26:07,224 - root - DEBUG - Download successful, storing TLE file offline
2018-11-04 18:26:07,227 - root - DEBUG - TLE file downloaded & saved 04/11/18 18:26

[SA7BNT]

Have you maked a chmod 755 on Decoder/medet_arm??

[gvandela]

The GRC script returns code 1 on my setup, which does produce images, so that should be fine.
To validate the received files, you can try manually decoding them with medet_arm on you raspberry pi.
Also, check how much CPU time the GRC script uses when it's receiving. You can run the GRC script stand alone and monitor the CPU time/memory with "top" or "htop". I don't know how much margin to expect on a raspberry pi 2. I only ever ran it on a 3 model B.
You could try decoding that .s file on another machine as well, with medet or lrptofflinedecoder from Oleg.
Edit: I just noticed no .s file is being produced. This could indicate a GRC script problem after all. Check if you're not maxing out on the raspberry pi 2 cpu(s).

[gvandela]

I remember I designed the GRC script on a laptop, and then had to tune down some filters in the GRC script so the raspberry pi 3 model B CPU cores would not max out. As the raspberry pi 2 is a little less performing, I suspect this could be the issue. It will be obvious if you see 100% CPU usage on any core.
I'm not sure which GRC blocks are the computational heavy ones, but there might be margin to still tune this down further, e.g. the filter rolloff of the translating filter could be backed-off more:
line 61:
self.freq_xlating_fir_filter_xxx_0 = filter.freq_xlating_fir_filter_ccc(decimation, (firdes.low_pass(1,samp_rate,BPF_width/2,20e3)), Tuning_offset, samp_rate)
The factor 20e3 could be increased, say 30e3... 40e3. I have no idea what the margin is or what the trade-off is, but this could reduce how computational intensive this filter is.

[raspyweather]

We definitely should add some more logging.
The GRC Script could not access the SDR due to some weird reason https://www.reddit.com/r/RTLSDR/wiki/blacklist_dvb_usb_rtl28xxu
I can't say if this fixed the issue yet, but I'll have a look.

[gvandela]

Sounds like the issue @SA7BNT had. Fingers crossed for both of ya!
As for the logging, I only catch things from the scheduler script. The GRC script was working by the time I got to writing the scheduler, so I didn't need any debug info then. Sure sounds like a good idea. As always, feel free ;)

[raspyweather]

2018-11-05 10:00:25,460 - root - DEBUG - trying TLE download...
2018-11-05 10:00:26,053 - root - DEBUG - Download successful, storing TLE file offline
2018-11-05 10:00:26,054 - root - DEBUG - TLE file downloaded & saved 05/11/18 10:00
2018-11-05 10:00:26,138 - root - DEBUG - waiting for positive satellite elevation
2018-11-05 11:25:00,875 - root - DEBUG - start GRC script
2018-11-05 11:25:01,018 - root - DEBUG - started /FTP/meteor/MeteorRpiReceiver/GRC/METEOR_M2_v04_noGUI.py with PID:10204 ['/usr/bin/python', '/FTP/meteor/MeteorRpiReceiver/GRC/METEOR_M2_v04_noGUI.py'] started at 2018-11-05 11:25:01.017709
2018-11-05 11:38:17,939 - root - DEBUG - stopping GRC script
2018-11-05 11:38:17,956 - root - DEBUG - GRC script ended with return code: 0
2018-11-05 11:38:37,992 - root - DEBUG - removed old file /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_05112018_0944.s
2018-11-05 11:38:38,001 - root - DEBUG - running: ./Decoder/medet_arm /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_05112018_1125.s /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_05112018_1125 -Q -b 64 -g 65 -r 68
2018-11-05 11:38:38,031 - root - DEBUG - running: ./Decoder/medet_arm /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_05112018_1125.s /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_05112018_1125_2 -Q -b 66 -g 67 -r 69
2018-11-05 11:38:38,051 - root - DEBUG - 1st medet ran with returncode: 126
2018-11-05 11:38:38,056 - root - DEBUG - 2nd medet ran with returncode: 126
2018-11-05 11:38:38,058 - root - DEBUG - decode_capture returned file name: meteor_LRPT_05112018_1125 & meteor_LRPT_05112018_1125_2
2018-11-05 11:38:38,060 - root - DEBUG - detecting blanks: no raw image was found
2018-11-05 11:38:38,061 - root - DEBUG - no e-mail sent as there was no decoded image
2018-11-05 11:38:38,062 - root - DEBUG - all done, start over for next pass

now I get a different error message, what's left to fix?

[gvandela]

Did you run the GRC script separately and check the cpu load? Maybe the GRC script is producing "corrupt" .s files because it cannot calculate all the samples.

Try to run the medet decoder separately as well, without the -Q option and see what it reports.

[raspyweather]

The CPU load seems pretty okay and is below 50% typically. The GRC Script generates .s files, but I did not try the medet decoder yet. I'll report to you at the weekend.

[gvandela]

That's kind of less than expected. On my raspberry pi 3 b+ all cores are above 50%, with one core around 90%! So it almost sounds like certain GRC blocks are not being executed?
After reading about the differences between raspberry pi 2 and 3, I'd be surprised if the GRC script would run on a raspberry pi 2 actually...

[raspyweather]

And to be a little more precise, I've got the Raspi 2B with 4 cores and GRC is using two cores at around 90% and the other two cores around 10 to 30%.

Now I get .s files, no error messages anymore but also no images :(

2018-11-10 21:15:42,491 - root - DEBUG - scheduler_v0.2.9 (no doppler) started on 10/11/18 at local 21:15
2018-11-10 21:15:42,501 - root - DEBUG - GRC script: /FTP/meteor/MeteorRpiReceiver/GRC/METEOR_M2_v04_noGUI.py
2018-11-10 21:15:42,505 - root - DEBUG - Location: 49:22:40.8N, 9:38:20.4E, 10.0m elevation
2018-11-10 21:15:42,506 - root - DEBUG - Sat name: METEOR-M 2
2018-11-10 21:15:42,528 - root - DEBUG - trying TLE download...
2018-11-10 21:15:42,946 - root - DEBUG - Download successful, storing TLE file offline
2018-11-10 21:15:42,948 - root - DEBUG - TLE file downloaded & saved 10/11/18 21:15
2018-11-10 21:15:42,954 - root - DEBUG - waiting for positive satellite elevation
2018-11-10 21:15:42,955 - root - DEBUG - start GRC script
2018-11-10 21:15:42,965 - root - DEBUG - started /FTP/meteor/MeteorRpiReceiver/GRC/METEOR_M2_v04_noGUI.py with PID:1704 ['/usr/bin/python', '/FTP/meteor/MeteorRpiReceiver/GRC/METEOR_M2_v04_noGUI.py'] started at 2018-11-10 21:15:42.965255
2018-11-10 21:27:41,589 - root - DEBUG - stopping GRC script
2018-11-10 21:27:41,651 - root - DEBUG - GRC script ended with return code: 0
2018-11-10 21:28:01,740 - root - DEBUG - running: ./Decoder/medet_arm /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_10112018_2115.s /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_10112018_2115 -Q -b 64 -g 65 -r 68
2018-11-10 21:28:01,754 - root - DEBUG - running: ./Decoder/medet_arm /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_10112018_2115.s /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_10112018_2115_2 -Q -b 66 -g 67 -r 69
2018-11-10 21:28:01,840 - root - DEBUG - 1st medet ran with returncode: 0
2018-11-10 21:28:01,843 - root - DEBUG - 2nd medet ran with returncode: 0
2018-11-10 21:28:01,845 - root - DEBUG - running: ./Decoder/medet_arm /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_10112018_2112.s /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_10112018_2112 -Q -b 64 -g 65 -r 68
2018-11-10 21:28:01,857 - root - DEBUG - running: ./Decoder/medet_arm /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_10112018_2112.s /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_10112018_2112_2 -Q -b 66 -g 67 -r 69
2018-11-10 21:28:01,913 - root - DEBUG - 1st medet ran with returncode: 0
2018-11-10 21:28:01,923 - root - DEBUG - 2nd medet ran with returncode: 0
2018-11-10 21:28:01,926 - root - DEBUG - removed old file /FTP/meteor/MeteorRpiReceiver/Data/meteor_LRPT_10112018_1932.s
2018-11-10 21:28:01,927 - root - DEBUG - decode_capture returned file name: meteor_LRPT_10112018_2112 & meteor_LRPT_10112018_2112_2
2018-11-10 21:28:01,928 - root - DEBUG - detecting blanks: no raw image was found
2018-11-10 21:28:01,929 - root - DEBUG - no e-mail sent as there was no decoded image
2018-11-10 21:28:01,930 - root - DEBUG - all done, start over for next pass
2018-11-10 21:28:01,931 - root - DEBUG - trying TLE download...
2018-11-10 21:28:02,434 - root - DEBUG - Download successful, storing TLE file offline
2018-11-10 21:28:02,435 - root - DEBUG - TLE file downloaded & saved 10/11/18 21:28

Edit

I've added a complete log file for more details.
scheduler_v0.2.9.log