flipperzero-firmware icon indicating copy to clipboard operation
flipperzero-firmware copied to clipboard

Send never ends

Open LoZio opened this issue 2 years ago • 15 comments

Describe the bug.

Created several datasets for CAME bruteforcing. Up to 50 codes per file Flipper sends the batch and stops. Narrowing down to the 20 per file, it starts sending but never completes, stays in the Send moving waveform screen. Also seems not to send codes since my gate never opens, while it does with the 50 batch file.

Reproduction

  1. Rename this file .sub and upload to Flipper (github does not accepts .sub) CAME_20_80.txt
  2. SubGhz=>Saved
  3. Select the file
  4. Send

It keeps sending forever. I can use any of the 20 codes files generated by CAME Bruteforcer

Target

No response

Logs

No response

Anything else?

Running 0.63.3

LoZio avatar Aug 04 '22 17:08 LoZio

Generating lots of 25 and 5 is still fine, completing and working. Something wrong with the 20 lines ones.

LoZio avatar Aug 04 '22 17:08 LoZio

image image I'm fine. starts and starts .... you have a slightly wrong RAW file, it should ideally start at a high level, but this is not necessary

Skorpionm avatar Aug 09 '22 18:08 Skorpionm

I understand the file is not well formed, will inform the developer of the script. I do not understand if it is necessary to modify the firmware to avoid malformed files to be stuck.

LoZio avatar Aug 10 '22 06:08 LoZio

seems to be correct. i just downloaded yours

Skorpionm avatar Aug 10 '22 06:08 Skorpionm

seems to be correct. i just downloaded yours

This specific file does not work with 0.63.3. Also the developer noticed the problem, see issue 3 above on his repo.

LoZio avatar Aug 10 '22 06:08 LoZio

Please check latest firmware and reopen issue if it persists.

skotopes avatar Sep 06 '22 17:09 skotopes

Same file, same behavior. It goes in some infinite loop. Other batch sized work fine. No difference at all. Using 0.66.1

LoZio avatar Sep 07 '22 06:09 LoZio

@Skorpionm Can you check ?

skotopes avatar Sep 07 '22 06:09 skotopes

143083 [I][SubGhzFileEncoderWorker] Worker start 143113 [I][SubGhzFileEncoderWorker] Start transmission 143118 [E][SubGhzFileEncoderWorker] Invalid level in the stream 143183 [D][FuriHalSubGhz] Loading custom preset 143185 [D][FuriHalSubGhz] Reg[0]: 02=0D 143186 [D][FuriHalSubGhz] Reg[2]: 03=07 143189 [D][FuriHalSubGhz] Reg[4]: 08=32 143191 [D][FuriHalSubGhz] Reg[6]: 0B=06 143192 [D][FuriHalSubGhz] Reg[8]: 14=00 143194 [D][FuriHalSubGhz] Reg[10]: 13=00 143196 [D][FuriHalSubGhz] Reg[12]: 12=30 143198 [D][FuriHalSubGhz] Reg[14]: 11=32 143200 [D][FuriHalSubGhz] Reg[16]: 10=17 143202 [D][FuriHalSubGhz] Reg[18]: 18=18 143204 [D][FuriHalSubGhz] Reg[20]: 19=18 143206 [D][FuriHalSubGhz] Reg[22]: 1D=91 143208 [D][FuriHalSubGhz] Reg[24]: 1C=00 143210 [D][FuriHalSubGhz] Reg[26]: 1B=07 143212 [D][FuriHalSubGhz] Reg[28]: 20=FB 143214 [D][FuriHalSubGhz] Reg[30]: 22=11 143216 [D][FuriHalSubGhz] Reg[32]: 21=B6 143218 [D][FuriHalSubGhz] PA[34]: 00 143219 [D][FuriHalSubGhz] PA[35]: 00 143223 [D][FuriHalSubGhz] PA[36]: 00 143225 [D][FuriHalSubGhz] PA[37]: C0 143227 [D][FuriHalSubGhz] PA[38]: 00 143228 [D][FuriHalSubGhz] PA[39]: 00 143230 [D][FuriHalSubGhz] PA[40]: 00 143232 [D][FuriHalSubGhz] PA[41]: 00 143234 [D][FuriHalSubGhz] PA[42]: 00 143236 [D][FuriHalSubGhz] PA[43]: 00 143241 [D][DolphinState] icounter 2, butthurt 0 143393 [I][SubGhzFileEncoderWorker] End read file 144637 [I][SubGhzFileEncoderWorker] End transmission 144639 [D][FuriHalSubGhz] Async TX Radio stats: on 384000us, off 1006413us, DutyCycle: 28% 144690 [I][SubGhzFileEncoderWorker] Worker stop

image

the same version, the same file, and I checked the normal behavior 40 times (sending) not 1 hang. show mi log in debug mode

Skorpionm avatar Sep 08 '22 19:09 Skorpionm

Found out how to log: here it is:


540190 [D][BrowserWorker] Load offset: 106 cnt: 100
546246 [D][BrowserWorker] End
549886 [I][SubGhzFileEncoderWorker] Worker start
549985 [D][FuriHalSubGhz] Loading custom preset
549987 [D][FuriHalSubGhz] Reg[0]: 02=0D
549990 [D][FuriHalSubGhz] Reg[2]: 03=07
549992 [D][FuriHalSubGhz] Reg[4]: 08=32
549994 [D][FuriHalSubGhz] Reg[6]: 0B=06
549996 [D][FuriHalSubGhz] Reg[8]: 14=00
549998 [D][FuriHalSubGhz] Reg[10]: 13=00
550000 [D][FuriHalSubGhz] Reg[12]: 12=30
550002 [D][FuriHalSubGhz] Reg[14]: 11=32
550004 [D][FuriHalSubGhz] Reg[16]: 10=17
550007 [D][FuriHalSubGhz] Reg[18]: 18=18
550010 [D][FuriHalSubGhz] Reg[20]: 19=18
550012 [D][FuriHalSubGhz] Reg[22]: 1D=91
550014 [D][FuriHalSubGhz] Reg[24]: 1C=00
550016 [D][FuriHalSubGhz] Reg[26]: 1B=07
550018 [D][FuriHalSubGhz] Reg[28]: 20=FB
550020 [D][FuriHalSubGhz] Reg[30]: 22=11
550023 [D][FuriHalSubGhz] Reg[32]: 21=B6
550025 [D][FuriHalSubGhz] PA[34]:  00
550026 [D][FuriHalSubGhz] PA[35]:  00
550029 [D][FuriHalSubGhz] PA[36]:  00
550031 [D][FuriHalSubGhz] PA[37]:  C0
550033 [D][FuriHalSubGhz] PA[38]:  00
550035 [D][FuriHalSubGhz] PA[39]:  00
550036 [D][FuriHalSubGhz] PA[40]:  00
550038 [D][FuriHalSubGhz] PA[41]:  00
550039 [D][FuriHalSubGhz] PA[42]:  00
550042 [D][FuriHalSubGhz] PA[43]:  00
550045 [I][SubGhzFileEncoderWorker] Start transmission
550047 [E][SubGhzFileEncoderWorker] Slow flash read
550052 [D][DolphinState] icounter 532, butthurt 0
550071 [E][SubGhzFileEncoderWorker] Invalid level in the stream
557434 [D][FuriHalSubGhz] Async TX Radio stats: on 0us, off 0us, DutyCycle: nan%
557442 [I][SubGhzFileEncoderWorker] End read file
557444 [I][SubGhzFileEncoderWorker] End transmission
557450 [I][SubGhzFileEncoderWorker] Worker stop

LoZio avatar Sep 09 '22 10:09 LoZio

Screenshot-20220909-122609 While trying to send the first file this is the display of the Flipper Wave is moving but never completes, even after the log says Worker stop

LoZio avatar Sep 09 '22 10:09 LoZio

550047 [E][SubGhzFileEncoderWorker] Slow flash read

Says that he does not have time to read from the SD card. Try another SD card, even though it's stan. Do you have EXACTLY official firmware and not custom?

Skorpionm avatar Sep 12 '22 08:09 Skorpionm

Never used unofficial firmware

LoZio avatar Sep 12 '22 08:09 LoZio

Still here in 0.68.1

LoZio avatar Oct 06 '22 11:10 LoZio

I'll try to reproduce and fix it on this weekend.

skotopes avatar Oct 07 '22 17:10 skotopes

Still here in 0.70.1

LoZio avatar Nov 04 '22 09:11 LoZio

@LoZio can you show benchmark screen for you sd-card?

skotopes avatar Nov 04 '22 11:11 skotopes

I can reproduce this issue under some specific conditions, we'll address it in next update

skotopes avatar Nov 04 '22 11:11 skotopes

Screenshot-20221104-125944 Attached the benchmark. I do not think it is performance related since I have thousands of files on the same SD card and only the ones generated by camebruteforcer in 20 codes batch have this problem. Any other works fine. I understand this may be a problem with the generator, still Flipper should terminate the loop or say there's something wrong with the file.

LoZio avatar Nov 04 '22 12:11 LoZio

Your generator is emitting invalid code: there is an 634691 [E][SubGhzFileEncoderWorker] Invalid level in the stream. But that's not the issue, flipper can handle it.

Closest to what you described I can reproduce by simultaneously uploading big file to SD. We'll focus on fixing it first.

skotopes avatar Nov 04 '22 12:11 skotopes

Just to add some bits: I'm not uploading anything while airing that file, Flipper is in my hands disconnected from anything. I can run big batches (4k codes) and small batches (5 codes) with no problems, so that Invalid level must be somewhat related.

LoZio avatar Nov 04 '22 12:11 LoZio

Also please attach console/cli log with latest firmware

skotopes avatar Nov 04 '22 12:11 skotopes

Here you are, log from lates fw flipper-071.log

LoZio avatar Nov 04 '22 12:11 LoZio

89020550 [E][SubGhzFileEncoderWorker] Slow flash read

skotopes avatar Nov 04 '22 12:11 skotopes

Only for that specific file and after several SD formats/writes/rewrites since the issue was opened? An SD that run a Raspberry with no problems? Will try another, I have dozens.

LoZio avatar Nov 04 '22 12:11 LoZio

Yep, that is a good question why it happens.

skotopes avatar Nov 04 '22 12:11 skotopes

Tried on the fly the shi***est card I have here. 2Gb from dinosaur era. It completes. Attached also the benchmark.

flipper-slow-2g.txt

Screenshot-20221104-132621-2Gb

LoZio avatar Nov 04 '22 12:11 LoZio

sdcard in SPI mode is something very unpredictable, so even shitty cards may be surprisingly good and vice versa.

skotopes avatar Nov 04 '22 12:11 skotopes

Pretty sure it is strange, but I just took out a 16gb from a phone, formatted on the PC and put the contents of the original sd card (zip of the root) and slammed into the dolphin. It plays all the files I tested except the 20-batch ones, like the one from this issue. The SD layout is different since also the file listing now is ordered, the original one does not. So maybe SPI/Speed have a role here, but it is very-very curious that the same file creates the same problem with different SD, different SD layouts, formatted on different devices, still they transmit the other files. To add another test I run the 20-batch while attached to the power and on battery, same result.

LoZio avatar Nov 04 '22 12:11 LoZio

Anyway, we'll redesign preload process so it will explicitly tell about any issue like this one.

skotopes avatar Nov 04 '22 12:11 skotopes