***** FinalStage Detected ****** Stuck

[hikey]

Device : SHP-6
Rasp PI3

Stuck on Flinalstage detected / Connecting to Finalstage
***** Receiving FinalStage Request ****
REQ: Client closed connection while receiving request:
etc etc etc ...

I can ping the client

64 bytes from 192.168.4.1: icmp_seq=201 ttl=128 time=3.99 ms
64 bytes from 192.168.4.1: icmp_seq=202 ttl=128 time=21.3 ms
64 bytes from 192.168.4.1: icmp_seq=203 ttl=128 time=86.2 ms

But after many many tries it will not send sonoff.bin
Anything else i can try ?

[hikey]

Sometimes is shut down fast , sometimes it keeps going for a long time :

Setting up wifi scan
Setting up listener for FinalStage
***** FinalStage Detected ******
***** Connected to FinalStage ******
***** Receiving FinalStage Request ****
REQ: Client closed connection while receiving request:
***** FinalStage Detected ******
***** Connected to FinalStage ******
***** FinalStage Detected ******
***** Connected to FinalStage ******
Shutting down...
Getting interface into stable state
RTNETLINK answers: Cannot assign requested address
Done
Finished
Exiting....
Shutting down...
pi@raspberrypi:~/TuyOTA $

[hikey]

Little bit more information, i need to unplug and plugin again to see the closed connection message :

***** Connected to FinalStage ******
***** Receiving FinalStage Request ****
REQ: Client closed connection while receiving request:
***** FinalStage Detected ******

[SynAckFin]

Normally the FinalStage firmware will repeatedly try and fetch the firmware but it looks like yours is only trying once.
There are a couple of things you can do:

1. Run it with the following flags: ./tuyota -b 2 -t 3600
   This will make it run for an hour and you can then try waiting or powering off and on.
   You could also, in another terminal, run the following:
   tcpdump -s0 -n -i wlan0 port 8080
   This will show you the connection attempts coming in from the device so you can a least see if anything is happening.

2. Run a webserver, on the pi, listening to port 8080 and all interfaces, and put the image_arduino.bin image into a folder called ota under the webservers document root.
   Then run the following commands:

ip a add 192.168.4.2/24 dev wlan0
ip link set wlan0 down
iwconfig wlan0 mode manager
iwconfig wlan0 essid off
ip link set wlan0 up
iwconfig wlan0 essid FinalStage

You should be able to ping 192.168.4.1 and the device should get the firmware from your webserver.

[hikey]

Hi,

First of all thanks for the help.

For option 1 i see all the time :
( i need to restart tcpdump quickly, because the script put wlan0 down and tcpdump stop)

root@raspberrypi:/home/pi# tcpdump -s0 -n -i wlan0 port 8080
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on wlan0, link-type EN10MB (Ethernet), capture size 262144 bytes
19:28:34.541095 IP 192.168.4.1.31282 > 192.168.4.2.8080: Flags [S], seq 6511, win 5840, options [mss 1460], length 0
19:28:34.541192 IP 192.168.4.2.8080 > 192.168.4.1.31282: Flags [S.], seq 4204425791, ack 6512, win 29200, options [mss 1460], length 0
19:28:34.542351 IP 192.168.4.1.4614 > 192.168.4.2.8080: Flags [S], seq 6563, win 5840, options [mss 1460], length 0
19:28:34.542420 IP 192.168.4.2.8080 > 192.168.4.1.4614: Flags [S.], seq 719401271, ack 6564, win 29200, options [mss 1460], length 0
19:28:34.543631 IP 192.168.4.1.4614 > 192.168.4.2.8080: Flags [S], seq 6563, win 5840, options [mss 1460], length 0
19:28:34.543660 IP 192.168.4.2.8080 > 192.168.4.1.4614: Flags [S.], seq 719401271, ack 6564, win 29200, options [mss 1460], length 0
19:28:34.546163 IP 192.168.4.1.31282 > 192.168.4.2.8080: Flags [R.], seq 1, ack 1, win 5840, length 0
19:28:34.547297 IP 192.168.4.1.4614 > 192.168.4.2.8080: Flags [.], ack 1, win 5840, length 0
19:28:34.548748 IP 192.168.4.1.4614 > 192.168.4.2.8080: Flags [F.], seq 1, ack 1, win 5840, length 0
19:28:34.549233 IP 192.168.4.2.8080 > 192.168.4.1.4614: Flags [F.], seq 1, ack 2, win 29200, length 0
19:28:34.550549 IP 192.168.4.1.4614 > 192.168.4.2.8080: Flags [.], ack 1, win 5840, length 0
19:28:34.552236 IP 192.168.4.1.4614 > 192.168.4.2.8080: Flags [.], ack 2, win 5839, length 0
tcpdump: pcap_loop: The interface went down
12 packets captured
12 packets received by filter
0 packets dropped by kernel
root@raspberrypi:/home/pi#

Result on other script :

***** Connected to FinalStage ******
***** Receiving FinalStage Request ****
REQ: Client closed connection while receiving request:
***** FinalStage Detected ******
***** Connected to FinalStage ******
***** FinalStage Detected ******

Option 2 :
I can ping 192,168.4.1 , on 8080 i listen on all ports but i see no traffic coming in.
If i unplug the plug, i am disconnected from FinalStage, and when i plug it back in i need to reconnect quickly. I seems not to work.
Any other suggestions ?

[SynAckFin]

The tcpdump shows that the device is trying several times a second to get the firmware,

Reboot the machine so as to make sure nothing is running that shouldn't be.
Turn your device on.
Run the following commands:

ip a add 192.168.4.2/24 dev wlan0
ip link set wlan0 down
iwconfig wlan0 mode manager
iwconfig wlan0 essid off
ip link set wlan0 up
iwconfig wlan0 essid FinalStage

Try pinging 192.168.4.1 you should get a response.
In another terminal run:

tcpdump -s0 -n -i wlan0 port 8080

The output should be this repeating:

19:54:16.725720 IP 192.168.4.1.49574 > 192.168.4.2.8080: Flags [S], seq 1445874303, win 29200, options [mss 1460,sackOK,TS val 636207085 ecr 0,nop,wscale 7], length 0
19:54:16.725753 IP 192.168.4.2.8080 > 192.168.4.1.49574: Flags [R.], seq 0, ack 1445874304, win 0, length 0

Leave it running as it shows the device is actively trying to complete the upgrade.
Now start your webserver. The tcpdump output should change and it should complete the install. If it doesn't then don't stop anything just run the following command:

netstat -tan | grep LISTEN

and let me know what the output is.

[hikey]

root@raspberrypi:/etc/apache2/sites-enabled# service apache2 stop
root@raspberrypi:/etc/apache2/sites-enabled# service apache2 start
root@raspberrypi:/etc/apache2/sites-enabled# netstat -tan | grep LISTEN
tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN
tcp 0 0 127.0.0.1:6010 0.0.0.0:* LISTEN
tcp 0 0 127.0.0.1:6011 0.0.0.0:* LISTEN
tcp 0 0 127.0.0.1:6012 0.0.0.0:* LISTEN
tcp6 0 0 :::8080 :::* LISTEN
tcp6 0 0 :::22 :::* LISTEN
tcp6 0 0 ::1:6010 :::* LISTEN
tcp6 0 0 ::1:6011 :::* LISTEN
tcp6 0 0 ::1:6012 :::* LISTEN

When i plug it in , i see ony one run of trying to connect to 8080 but i see nothing in the apache log.

[hikey]

No that is not correct what i am saying, when i plug in it i see this on tcpdump.

20:54:16.659971 IP 192.168.4.2.8080 > 192.168.4.1.26340: Flags [R.], seq 0, ack 8528, win 0, length 0
20:54:17.164984 IP 192.168.4.1.30138 > 192.168.4.2.8080: Flags [S], seq 8597, win 5840, options [mss 1460], length 0
20:54:17.165032 IP 192.168.4.2.8080 > 192.168.4.1.30138: Flags [R.], seq 0, ack 8598, win 0, length 0
20:54:17.671011 IP 192.168.4.1.2985 > 192.168.4.2.8080: Flags [S], seq 8667, win 5840, options [mss 1460], length 0
20:54:17.671063 IP 192.168.4.2.8080 > 192.168.4.1.2985: Flags [R.], seq 0, ack 8668, win 0, length 0
20:54:18.173879 IP 192.168.4.1.5420 > 192.168.4.2.8080: Flags [S], seq 8739, win 5840, options [mss 1460], length 0
20:54:18.173933 IP 192.168.4.2.8080 > 192.168.4.1.5420: Flags [R.], seq 0, ack 8740, win 0, length 0
20:54:18.676260 IP 192.168.4.1.21953 > 192.168.4.2.8080: Flags [S], seq 8811, win 5840, options [mss 1460], length 0
20:54:18.676313 IP 192.168.4.2.8080 > 192.168.4.1.21953: Flags [R.], seq 0, ack 8812, win 0, length 0
20:54:19.178853 IP 192.168.4.1.4198 > 192.168.4.2.8080: Flags [S], seq 8885, win 5840, options [mss 1460], length 0
20:54:19.178905 IP 192.168.4.2.8080 > 192.168.4.1.4198: Flags [R.], seq 0, ack 8886, win 0, length 0
20:54:19.684016 IP 192.168.4.1.8011 > 192.168.4.2.8080: Flags [S], seq 8959, win 5840, options [mss 1460], length 0
20:54:19.684069 IP 192.168.4.2.8080 > 192.168.4.1.8011: Flags [R.], seq 0, ack 8960, win 0, length 0
20:54:20.187405 IP 192.168.4.1.8584 > 192.168.4.2.8080: Flags [S], seq 9035, win 5840, options [mss 1460], length 0
20:54:20.187454 IP 192.168.4.2.8080 > 192.168.4.1.8584: Flags [R.], seq 0, ack 9036, win 0, length 0
20:54:20.689507 IP 192.168.4.1.24899 > 192.168.4.2.8080: Flags [S], seq 9111, win 5840, options [mss 1460], length 0
20:54:20.689557 IP 192.168.4.2.8080 > 192.168.4.1.24899: Flags [R.], seq 0, ack 9112, win 0, length 0
20:54:21.194365 IP 192.168.4.1.13820 > 192.168.4.2.8080: Flags [S], seq 9189, win 5840, options [mss 1460], length 0
20:54:21.194418 IP 192.168.4.2.8080 > 192.168.4.1.13820: Flags [R.], seq 0, ack 9190, win 0, length 0
20:54:21.696358 IP 192.168.4.1.18991 > 192.168.4.2.8080: Flags [S], seq 9267, win 5840, options [mss 1460], length 0
20:54:21.696415 IP 192.168.4.2.8080 > 192.168.4.1.18991: Flags [R.], seq 0, ack 9268, win 0, length 0
20:54:22.198505 IP 192.168.4.1.27098 > 192.168.4.2.8080: Flags [S], seq 9347, win 5840, options [mss 1460], length 0
20:54:22.198555 IP 192.168.4.2.8080 > 192.168.4.1.27098: Flags [R.], seq 0, ack 9348, win 0, length 0
20:54:22.700982 IP 192.168.4.1.22332 > 192.168.4.2.8080: Flags [S], seq 9427, win 5840, options [mss 1460], length 0
20:54:22.701045 IP 192.168.4.2.8080 > 192.168.4.1.22332: Flags [R.], seq 0, ack 9428, win 0, length 0
20:54:23.202832 IP 192.168.4.1.19793 > 192.168.4.2.8080: Flags [S], seq 9509, win 5840, options [mss 1460], length 0
20:54:23.202898 IP 192.168.4.2.8080 > 192.168.4.1.19793: Flags [R.], seq 0, ack 9510, win 0, length 0
20:54:23.705654 IP 192.168.4.1.17880 > 192.168.4.2.8080: Flags [S], seq 9591, win 5840, options [mss 1460], length 0
20:54:23.705714 IP 192.168.4.2.8080 > 192.168.4.1.17880: Flags [R.], seq 0, ack 9592, win 0, length 0
20:54:24.210925 IP 192.168.4.1.23968 > 192.168.4.2.8080: Flags [S], seq 9675, win 5840, options [mss 1460], length 0
20:54:24.210993 IP 192.168.4.2.8080 > 192.168.4.1.23968: Flags [R.], seq 0, ack 9676, win 0, length 0
20:54:24.713306 IP 192.168.4.1.16291 > 192.168.4.2.8080: Flags [S], seq 9759, win 5840, options [mss 1460], length 0
20:54:24.713364 IP 192.168.4.2.8080 > 192.168.4.1.16291: Flags [R.], seq 0, ack 9760, win 0, length 0
20:54:25.215773 IP 192.168.4.1.22950 > 192.168.4.2.8080: Flags [S], seq 9845, win 5840, options [mss 1460], length 0
20:54:25.215835 IP 192.168.4.2.8080 > 192.168.4.1.22950: Flags [R.], seq 0, ack 9846, win 0, length 0
20:54:25.718350 IP 192.168.4.1.2167 > 192.168.4.2.8080: Flags [S], seq 9931, win 5840, options [mss 1460], length 0
20:54:25.718407 IP 192.168.4.2.8080 > 192.168.4.1.2167: Flags [R.], seq 0, ack 9932, win 0, length 0
20:54:26.220417 IP 192.168.4.1.32289 > 192.168.4.2.8080: Flags [S], seq 10019, win 5840, options [mss 1460], length 0
20:54:26.220472 IP 192.168.4.2.8080 > 192.168.4.1.32289: Flags [R.], seq 0, ack 10020, win 0, length 0
20:54:26.726539 IP 192.168.4.1.4536 > 192.168.4.2.8080: Flags [S], seq 10107, win 5840, options [mss 1460], length 0
20:54:26.726592 IP 192.168.4.2.8080 > 192.168.4.1.4536: Flags [R.], seq 0, ack 10108, win 0, length 0
20:54:27.232711 IP 192.168.4.1.8271 > 192.168.4.2.8080: Flags [S], seq 10197, win 5840, options [mss 1460], length 0
20:54:27.232761 IP 192.168.4.2.8080 > 192.168.4.1.8271: Flags [R.], seq 0, ack 10198, win 0, length 0
20:54:27.734584 IP 192.168.4.1.3449 > 192.168.4.2.8080: Flags [S], seq 10287, win 5840, options [mss 1460], length 0
20:54:27.734633 IP 192.168.4.2.8080 > 192.168.4.1.3449: Flags [R.], seq 0, ack 10288, win 0, length 0
20:54:28.237979 IP 192.168.4.1.29257 > 192.168.4.2.8080: Flags [S], seq 10379, win 5840, options [mss 1460], length 0
20:54:28.238031 IP 192.168.4.2.8080 > 192.168.4.1.29257: Flags [R.], seq 0, ack 10380, win 0, length 0
20:54:28.743084 IP 192.168.4.1.31323 > 192.168.4.2.8080: Flags [S], seq 10471, win 5840, options [mss 1460], length 0
20:54:28.743135 IP 192.168.4.2.8080 > 192.168.4.1.31323: Flags [R.], seq 0, ack 10472, win 0, length 0
20:54:29.245397 IP 192.168.4.1.25773 > 192.168.4.2.8080: Flags [S], seq 10565, win 5840, options [mss 1460], length 0
20:54:29.245445 IP 192.168.4.2.8080 > 192.168.4.1.25773: Flags [R.], seq 0, ack 10566, win 0, length 0
20:54:29.750608 IP 192.168.4.1.13717 > 192.168.4.2.8080: Flags [S], seq 10659, win 5840, options [mss 1460], length 0
20:54:29.750658 IP 192.168.4.2.8080 > 192.168.4.1.13717: Flags [R.], seq 0, ack 10660, win 0, length 0
20:54:30.256561 IP 192.168.4.1.5175 > 192.168.4.2.8080: Flags [S], seq 10755, win 5840, options [mss 1460], length 0
20:54:30.256614 IP 192.168.4.2.8080 > 192.168.4.1.5175: Flags [R.], seq 0, ack 10756, win 0, length 0
20:54:30.759292 IP 192.168.4.1.12646 > 192.168.4.2.8080: Flags [S], seq 10851, win 5840, options [mss 1460], length 0
20:54:30.759363 IP 192.168.4.2.8080 > 192.168.4.1.12646: Flags [R.], seq 0, ack 10852, win 0, length 0
20:54:31.263019 IP 192.168.4.1.4730 > 192.168.4.2.8080: Flags [S], seq 10949, win 5840, options [mss 1460], length 0
20:54:31.263082 IP 192.168.4.2.8080 > 192.168.4.1.4730: Flags [R.], seq 0, ack 10950, win 0, length 0
20:54:31.765466 IP 192.168.4.1.27320 > 192.168.4.2.8080: Flags [S], seq 11047, win 5840, options [mss 1460], length 0
20:54:31.765518 IP 192.168.4.2.8080 > 192.168.4.1.27320: Flags [R.], seq 0, ack 11048, win 0, length 0
20:54:32.268137 IP 192.168.4.1.27047 > 192.168.4.2.8080: Flags [S], seq 11147, win 5840, options [mss 1460], length 0
20:54:32.268190 IP 192.168.4.2.8080 > 192.168.4.1.27047: Flags [R.], seq 0, ack 11148, win 0, length 0
20:54:32.771547 IP 192.168.4.1.29510 > 192.168.4.2.8080: Flags [S], seq 11247, win 5840, options [mss 1460], length 0
20:54:32.771606 IP 192.168.4.2.8080 > 192.168.4.1.29510: Flags [R.], seq 0, ack 11248, win 0, length 0
20:54:33.275861 IP 192.168.4.1.5113 > 192.168.4.2.8080: Flags [S], seq 11349, win 5840, options [mss 1460], length 0
20:54:33.275914 IP 192.168.4.2.8080 > 192.168.4.1.5113: Flags [R.], seq 0, ack 11350, win 0, length 0
20:54:33.779010 IP 192.168.4.1.14040 > 192.168.4.2.8080: Flags [S], seq 11451, win 5840, options [mss 1460], length 0
20:54:33.779083 IP 192.168.4.2.8080 > 192.168.4.1.14040: Flags [R.], seq 0, ack 11452, win 0, length 0
20:54:34.282548 IP 192.168.4.1.14374 > 192.168.4.2.8080: Flags [S], seq 11555, win 5840, options [mss 1460], length 0
20:54:34.282623 IP 192.168.4.2.8080 > 192.168.4.1.14374: Flags [R.], seq 0, ack 11556, win 0, length 0
20:54:34.785324 IP 192.168.4.1.31280 > 192.168.4.2.8080: Flags [S], seq 11659, win 5840, options [mss 1460], length 0
20:54:34.785376 IP 192.168.4.2.8080 > 192.168.4.1.31280: Flags [R.], seq 0, ack 11660, win 0, length 0
20:54:35.287650 IP 192.168.4.1.5484 > 192.168.4.2.8080: Flags [S], seq 11765, win 5840, options [mss 1460], length 0
20:54:35.287701 IP 192.168.4.2.8080 > 192.168.4.1.5484: Flags [R.], seq 0, ack 11766, win 0, length 0

So it keeps polling port 8080, but when i start apache2 it stop

20:55:35.150871 IP 192.168.4.1.21079 > 192.168.4.2.8080: Flags [S], seq 31899, win 5840, options [mss 1460], length 0
20:55:35.150937 IP 192.168.4.2.8080 > 192.168.4.1.21079: Flags [R.], seq 0, ack 31900, win 0, length 0
20:55:35.653211 IP 192.168.4.1.24600 > 192.168.4.2.8080: Flags [S], seq 32131, win 5840, options [mss 1460], length 0
20:55:35.653374 IP 192.168.4.2.8080 > 192.168.4.1.24600: Flags [S.], seq 2731580240, ack 32132, win 29200, options [mss 1460], length 0
20:55:35.657836 IP 192.168.4.1.24600 > 192.168.4.2.8080: Flags [.], ack 1, win 5840, length 0
20:55:35.660585 IP 192.168.4.1.24600 > 192.168.4.2.8080: Flags [F.], seq 1, ack 1, win 5840, length 0
20:55:35.661090 IP 192.168.4.2.8080 > 192.168.4.1.24600: Flags [F.], seq 1, ack 2, win 29200, length 0
20:55:35.662413 IP 192.168.4.1.24600 > 192.168.4.2.8080: Flags [.], ack 2, win 5839, length 0

and then nothing happen, i see nothing in the log of apache either.
Very strange.

[SynAckFin]

That tells me quite a bit.
Before you start apache you get this:

20:54:34.785324 IP 192.168.4.1.31280 > 192.168.4.2.8080: Flags [S], seq 11659, win 5840, options [mss 1460], length 0
20:54:34.785376 IP 192.168.4.2.8080 > 192.168.4.1.31280: Flags [R.], seq 0, ack 11660, win 0, length 0

When the device wants to talk to the host it sends a SYN packet on port 8080 which is denoted by the [S] but because the host isn't listening yet it sends a RST response ([R]).
When you start apache this changes.
The device sends a SYN the host responds with a SYN ACK and the device then sends an ACK and the connection between the device and the host is now complete
That sequence is shown the following lines:

20:55:35.653211 IP 192.168.4.1.24600 > 192.168.4.2.8080: Flags [S], seq 32131, win 5840, options [mss 1460], length 0
20:55:35.653374 IP 192.168.4.2.8080 > 192.168.4.1.24600: Flags [S.], seq 2731580240, ack 32132, win 29200, options [mss 1460], length 0
20:55:35.657836 IP 192.168.4.1.24600 > 192.168.4.2.8080: Flags [.], ack 1, win 5840, length 0

What is supposed to happen next is that the device then sends the HTTP request but it doesn't, instead it send this packet:

20:55:35.660585 IP 192.168.4.1.24600 > 192.168.4.2.8080: Flags [F.], seq 1, ack 1, win 5840, length 0

This is known as a FIN packet ([F]) and it is the device closing down the connection.This followed by the host closing its part and finally the device acknowledging it.
(Syn, Ack, Fin that reminds me of something)

Unfortunately, this is bad news. It means the FinalStage firmware isn't working the way it is supposed to and your device is unlikely to get the tasmota firmware. There isn't anything that can be done other than taking it apart and connecting to it via a serial connection..

About the only thing you can try at this stage is to leave it connected the way it is overnight and hope it somehow kicks into life and fetches the firmware. Alternatively you could try repeatedly powering off and on and using tcpdump to see if it has hung again.

[hikey]

I also tried to flash it with sonota.exe (FinalStage) for windows but it has exactly the same effect, so now we know why.
This week i get a lot of these plugs, so i will try if i was just unlucky with this one or there is something different in this model.
Thanks for helping out, i will update here if this was a one time problem, and will do some more attempts with the solutions you gave me.

[SynAckFin]

You might do better trying tuya-convert instead. I think their interim stage is better than mine and less prone to error.