@rickkas7 is there something in here that is worth filing as a firmware bug?
@rickkas7 @zach the odd thing is that with the main server which is failing on your program, we run many ftp connections using a simple python script in Telit HE910 modems and there is rarely a failure, they use exactly the same USER and PASS sequences as we are using here and they negotiate it all successfully.
Admitedly we are using the Telit TCIP stack, so I am not sure what they do at that level but it is all rock solid
Also I have never seen it fail using the simple Microsoft Telnet command line program, the server always responds to an open, user and pass
@rickkas7 @zach Rick, just trying to run your program repeatedly on the ftp.nrie.com.au server and looking for what is different.
After your program opens the socket it reads 128 bytes of 322 bytes pending. This is because the server sends a very long welcome message. Below is the full logon using Microsoft Telnet
Then you ( I say you but I realise it is the TCPClient doing it) exchange the following sequence with the ublox
96.138 AT send 15 “AT+USOWR=1,24\r\n”
96.138 AT read + 18 “\r\n+UUSORD: 1,194\r\n”
Socket 1: handle 1 has 194 bytes pending
96.150 AT read > 3 “\r\n@”
96.200 AT send 24 “USER robyn@nrie.com.au\r\n”
96.340 AT read + 16 “\r\n+USOWR: 1,24\r\n”
96.350 AT read OK 6 “\r\nOK\r\n”
The first line is OK, sets the ublox in binary syntax mode (ublox AT manual page 495), ublox responds with information saying 194 bytes from the previous server reply are still pending. That is OK. modem then sends the @\r\n which you recognise and then send the USER string “USER robyn@nrie.com.au\r\n” , all OK
The modem then sends an OK response.
I think that there are two things that could go wrong here
a. The manual says that “After the @ prompt reception, wait a minimum of 50ms before sending data”. I cannot determine if this condition is met, maybe you are able to confirm that?
b. The manual says (p496) • TCP socket: A write operation performed when the remote host has closed its part of the TCP connection (FIN packet received by the module) - but there is still data to be read from the socket - is accepted. This behaviour differs from LISA-U / SARA-U series, where this operation returns an error. It is suggested to read all the socket data before triggering a write command, to avoid this situation. Now we are using the SARA module and there is still this unread data in the socket, left over from the welcome response. Are we defying gravity here?
The last part of the welcome response is then returned and you read it and print as
got line 220-You are user number 13 of 500 allowed.
failed to login, error 220-You are user number 13 of 500 allowed.
Obviously the response you are reading is the left over welcome and not 331 response code to the USER command. This is why your logon is failing
Am I making sense??? Is there any clue here as to what the problem is?
thanks
This is the complete transcript output from your program when trying to connect to ftp.nrie.com.au
** connecting to ftp.nrie.com.au:21
92.805 AT send 31 “AT+UDNSRN=0,“ftp.nrie.com.au”\r\n”
94.305 AT read + 28 “\r\n+UDNSRN: “173.248.187.5”\r\n”
94.315 AT read OK 6 “\r\nOK\r\n”
socketSocket(TCP)
94.315 AT send 12 “AT+USOCR=6\r\n”
94.325 AT read + 13 “\r\n+USOCR: 1\r\n”
94.335 AT read OK 6 “\r\nOK\r\n”
Socket 1: handle 1 was created
socketConnect(1,port:21)
94.335 AT send 31 “AT+USOCO=1,“173.248.187.5”,21\r\n”
95.496 AT read OK 6 “\r\nOK\r\n”
96.086 AT read + 18 “\r\n+UUSORD: 1,322\r\n”
Socket 1: handle 1 has 322 bytes pending
socketRecv: _cbUSORD
96.106 AT send 16 “AT+USORD=1,128\r\n”
96.126 AT read + 146 "\r\n+USORD: 1,128,\"220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------\r\n220-You are user number 13 of 500 allowed.\r\n220-Local time is now\""
96.138 AT read OK 6 "\r\nOK\r\n"
got line 220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------
96.138 AT send 15 "AT+USOWR=1,24\r\n"
96.138 AT read + 18 "\r\n+UUSORD: 1,194\r\n"
Socket 1: handle 1 has 194 bytes pending
96.150 AT read > 3 “\r\n@”
96.200 AT send 24 “USER robyn@nrie.com.au\r\n”
96.340 AT read + 16 “\r\n+USOWR: 1,24\r\n”
96.350 AT read OK 6 “\r\nOK\r\n”
got line 220-You are user number 13 of 500 allowed.
failed to login, error 220-You are user number 13 of 500 allowed.
cleanupAndWait
socketClose(1)
96.350 AT send 12 “AT+USOCL=1\r\n”
96.622 AT read OK 6 “\r\nOK\r\n”
socketFree(1)
** ready for next send
1 Like
Ah ha! That’s the hint that I needed. I wrote the code to handle continuation lines, but it had a bug and it wasn’t exercised by my server.
Add this global variable:
bool continuation = false;
And change processResponse to this:
bool processResponse() {
bool checkAgain = false;
char *endOfLine = strstr(responseBuf, "\015\012");
if (endOfLine) {
size_t lineSizeWithEOL = endOfLine - responseBuf + 2;
*endOfLine = 0;
if (responseBuf[3] == ' ') {
continuation = false;
int code;
if (sscanf(responseBuf, "%03d", &code) == 1) {
Serial.printlnf("code %d", code);
while(processCommandStateMachine(code)) {
//
}
}
else {
Serial.printlnf("invalid line %s", responseBuf);
}
}
else
if (continuation) {
Serial.printlnf("continuation %s", responseBuf);
}
else
if (responseBuf[3] == '-') {
Serial.printlnf("continuation start %s", responseBuf);
continuation = true;
}
else {
Serial.printlnf("unexpected line %s", responseBuf);
}
size_t bytesAfter = responseOffset - lineSizeWithEOL;
if (bytesAfter > 0) {
// There are possibly more lines in the buffer
memmove(responseBuf, &responseBuf[lineSizeWithEOL], bytesAfter);
responseOffset -= lineSizeWithEOL;
checkAgain = true;
}
else {
responseOffset = 0;
}
}
return checkAgain;
}
I successfully connected and uploaded 10 times to your server; it previously failed every time. Also, all of the connections gracefully shut down, not showing the oddity that I saw on my server.
This is what the connection log looked like:
** connecting to ftp.nrie.com.au:21
0000030000:DEBUG: virtual void TCPClient::stop() (192):_sock -1 closesocket
30.000 AT send 31 "AT+UDNSRN=0,\"ftp.nrie.com.au\"\r\n"
31.681 AT read + 28 "\r\n+UDNSRN: \"173.248.187.5\"\r\n"
31.691 AT read OK 6 "\r\nOK\r\n"
0000031691:DEBUG: virtual void TCPClient::stop() (192):_sock -1 closesocket
socketSocket(TCP)
31.691 AT send 12 "AT+USOCR=6\r\n"
31.701 AT read + 13 "\r\n+USOCR: 1\r\n"
31.711 AT read OK 6 "\r\nOK\r\n"
Socket 1: handle 1 was created
0000031711:DEBUG: virtual int TCPClient::connect(IPAddress, uint16_t, network_interface_t) (80):socket=1
0000031711:DEBUG: virtual int TCPClient::connect(IPAddress, uint16_t, network_interface_t) (98):_sock 1 connect
socketConnect(1,port:21)
31.722 AT send 31 "AT+USOCO=1,\"173.248.187.5\",21\r\n"
34.002 AT read OK 6 "\r\nOK\r\n"
0000034002:DEBUG: virtual int TCPClient::connect(IPAddress, uint16_t, network_interface_t) (100):_sock 1 connected=1
34.712 AT read + 18 "\r\n+UUSORD: 1,322\r\n"
Socket 1: handle 1 has 322 bytes pending
socketRecv: _cbUSORD
34.732 AT send 16 "AT+USORD=1,128\r\n"
34.752 AT read + 146 "\r\n+USORD: 1,128,\"220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------\r\n220-You are user number 54 of 500 allowed.\r\n220-Local time is now\""
34.764 AT read OK 6 "\r\nOK\r\n"
0000034764:DEBUG: virtual int TCPClient::available() (145):recv(=128)
continuation start 220---------- Welcome to Pure-FTPd [privsep] [TL 34.765 AT read + 18 "\r\n+UUSORD: 1,194\r\n"
Socket 1: handle 1 has 194 bytes pending
S] ----------
continuation 220-You are user number 54 of 500 allowed.
socketRecv: _cbUSORD
34.795 AT send 16 "AT+USORD=1,128\r\n"
34.815 AT read + 146 "\r\n+USORD: 1,128,\" 04:12. Server port: 21.\r\n220-This is a private system - No anonymous login\r\n220-IPv6 connections are also welcome on this serve\""
34.827 AT read OK 6 "\r\nOK\r\n"
0000034827:DEBUG: virtual int TCPClient::available() (145):recv(=128)
continuation 220-Local time is now 04:12. Server port: 21.
continuation 220-This is a private system - No anonymous login
34.828 AT read + 17 "\r\n+UUSORD: 1,66\r\n"
Socket 1: handle 1 has 66 bytes pending
socketRecv: _cbUSORD
34.848 AT send 15 "AT+USORD=1,66\r\n"
34.868 AT read + 83 "\r\n+USORD: 1,66,\"r.\r\n220 You will be disconnected after 15 minutes of inactivity.\r\n\""
34.879 AT read OK 6 "\r\nOK\r\n"
0000034889:DEBUG: virtual int TCPClient::available() (145):recv(=66)
continuation 220-IPv6 connections are also welcome on this server.
code 220
34.890 AT send 15 "AT+USOWR=1,24\r\n"
34.900 AT read > 3 "\r\n@"
34.950 AT send 24 "USER robyn@nrie.com.au\r\n"
35.090 AT read + 16 "\r\n+USOWR: 1,24\r\n"
35.100 AT read OK 6 "\r\nOK\r\n"
35.440 AT read + 17 "\r\n+UUSORD: 1,50\r\n"
Socket 1: handle 1 has 50 bytes pending
socketRecv: _cbUSORD
35.460 AT send 15 "AT+USORD=1,50\r\n"
35.470 AT read + 67 "\r\n+USORD: 1,50,\"331 User robyn@nrie.com.au OK. Password required\r\n\""
35.481 AT read OK 6 "\r\nOK\r\n"
0000035491:DEBUG: virtual int TCPClient::available() (145):recv(=50)
code 331
35.491 AT send 15 "AT+USOWR=1,16\r\n"
35.501 AT read > 3 "\r\n@"
35.551 AT send 16 "PASS relish321\r\n"
35.681 AT read + 16 "\r\n+USOWR: 1,16\r\n"
35.691 AT read OK 6 "\r\nOK\r\n"
36.071 AT read + 17 "\r\n+UUSORD: 1,43\r\n"
Socket 1: handle 1 has 43 bytes pending
socketRecv: _cbUSORD
36.091 AT send 15 "AT+USORD=1,43\r\n"
36.101 AT read + 60 "\r\n+USORD: 1,43,\"230 OK. Current restricted directory is /\r\n\""
36.112 AT read OK 6 "\r\nOK\r\n"
0000036122:DEBUG: virtual int TCPClient::available() (145):recv(=43)
code 230
logged in successfully!
3 Likes
@rickkas7, can you please republish the entire updated code or make the updates to the your original code post? 
1 Like
Good idea. I updated the original code above with the fixes.
2 Likes
@rickkas7 Thanks so much Rick, I tried to run it late tonight but it would not compile for me, too late for me to think now but I get the following compile error. I saved your updated program as ftp.ino
Does it compile for you? I can’t see the error, obviously a bracket missing but they seem to be matched.
Monday will be another day
I might have pasted the corrections incorrectly. I just updated the whole program from the one I built instead.
@rickkas7 Thanks Rick.
If you did update the code it made no difference, it still refused to compile with the particle compiler or from the Particle Dev . Same error as before. I eventually tracked it down to the processResponse() subroutine and had to put brackets around the section following the else at else if(continuation)… Modified code is here
else{
if (continuation) {
Serial.printlnf(“continuation %s”, responseBuf);
}
else
if (responseBuf[3] == ‘-’) {
Serial.printlnf(“continuation start %s”, responseBuf);
continuation = true;
}
else {
Serial.printlnf(“unexpected line %s”, responseBuf);
}
}
The compiler was really trying to tell me that it could not figure out what was going on at that else. I don’t know what compiler you were using but it must have decided it could do it.
Can you look at the way I have put brackets around that whole section and decide that is what you intended to do please. There are a couple of other ways of interpreting it but I would have to change it one way or the other.
The program, as modified above, is working, The big question is;
HAVE YOU MADE ANY CHANGE TO TCPCLIENT OUTSIDE OF VERSION 0.5.3???
I ask this because I can’t see anything wrong either with my ftp program or the other two libraries which were showing problems. Is there a possibility that including the debug output you are adding delays at those critical points where the ublox modem is requiring it? My device is running 0.5.3 and I am compiling locally from your source so I can’t see any difference between yours and mine apart from the debug side.Your routine still works if I comment out
//SerialDebugOutput debugOutput(9600, ALL_LEVEL); at the top.
My attempts generally did not wait for Particle.connected(), just Cellular.ready() but the inconsistencies I have were there regardless of what I waited for.
At this stage I will analyse your program in detail and see if I can spot the difference.
Thanks
Robyn
The compile error on the else statement is a weird Arduino pre-processor thing, apparently. If you insert this line at the top of the file the problem will go away:
#pragma SPARK_NO_PREPROCESSOR
I repeated the test on an Electron with non-debug 0.5.3 firmware using your server (the first one, that previously failed), and it still works fine:
Without all of the debug info, it looks like this:
** connecting to ftp.nrie.com.au:21
continuation start 220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------
continuation 220-You are user number 20 of 500 allowed.
continuation 220-Local time is now 06:32. Server port: 21.
continuation 220-This is a private system - No anonymous login
continuation 220-IPv6 connections are also welcome on this server.
code 220
code 331
code 230
logged in successfully!
code 250
directory set to FTP
code 227
** sending file: 20161107T103219.txt
making data connection to addr=173.248.187.5 port=35601
data connection established
code 150
STOR got OK to send data, response 150 Accepted data connection
** data sent successfully, 1024 bytes in 1280 ms
continuation start 226-File successfully transferred
code 226
** STOR successful, response 226 1.150 seconds (measured here), 0.87 Kbytes per second
continuation start 221-Goodbye. You uploaded 1 and downloaded 0 kbytes.
code 221
** QUIT successful, response 221 Logout.
cleanupAndWait
** ready for next send
I repeated the test 11 times and it worked every time for me.
1 Like
@rickkas7 @zach Thanks Rick for all the work you have done here. I have spent a good deal of sweat over what is the difference between your program and mine. I have even tried to change yours to make it crack. This is the conclusion I am coming to, I now have my program working well, at least for the last hour.
I included the SerialDebugOutput debugOutput(9600, ALL_LEVEL); in my program to see if it helped with understanding where the error was. As I have said before it seems as though the ublox modem is not sending short commands and so the ftp server does not answer. But what seems to be happening is that sometimes the Particle firmware does not ask for a read of the socket, hence nothing is received. I think I am right here.
This is a dump from my program, just the sign on to the server, get the welcome message and try to send a user name. This time it succeeds. The comments -stage 3 etc just tell me what part of my state engine is running.
Code string: 220
connectFTPServer - stage 3
Welcome received
connectFTPServer - stage 4
312.468 AT send 15 "AT+USOWR=0,22\r\n"
312.478 AT read > 3 "\r\n@"
312.528 AT send 22 "USER robyn@nrie.com.au"
312.668 AT read + 16 "\r\n+USOWR: 0,22\r\n"
312.678 AT read OK 6 "\r\nOK\r\n"
312.678 AT send 14 "AT+USOWR=0,1\r\n"
312.688 AT read > 3 "\r\n@"
312.738 AT send 1 "\r"
312.868 AT read + 15 "\r\n+USOWR: 0,1\r\n"
312.878 AT read OK 6 "\r\nOK\r\n"
312.878 AT send 14 "AT+USOWR=0,1\r\n"
312.888 AT read > 3 "\r\n@"
312.938 AT send 1 "\n"
313.068 AT read + 15 "\r\n+USOWR: 0,1\r\n"
313.078 AT read OK 6 "\r\nOK\r\n"
Function parseResponse Stage 1
Server response:
Function parseResponse Stage 2
Function parseResponse Stage 2
315.639 AT read + 17 "\r\n+UUSORD: 0,50\r\n"
Socket 0: handle 0 has 50 bytes pending
socketRecv: _cbUSORD
315.659 AT send 15 "AT+USORD=0,50\r\n"
315.679 AT read + 67 "\r\n+USORD: 0,50,\"331 User robyn@nrie.com.au OK. Password required\r\n\""
315.690 AT read OK 6 "\r\nOK\r\n"
Function parseResponse Stage 2
As can be seen the firmware is issuing AT+USORD commands to interpret my C code which is basically the line
int bytesRead = serverCmnd.read((uint8_t*)&cmdResponseBuffer[cCnt], bytesLeft);
When the response fails there are no AT+USORD commands sent, I can give the full dump but take my word for it at the moment. When the connection fails, the lead up to the read statement is exactly the same as when it succeeds, I have checked that the server is connected and bytesLeft etc are all OK, bytesRead returns -1 even though I execute the read() function 10 times with second breaks between them.
I think the issue is that when I send the user name (and likewise for the other commands) I used the following code
serverCmnd.println("USER " + username); where username is a String. Particle causes that to be sent as the code I have dumped above and there are quite a few AT writes there. My guess is that the modem is not happy with these extra writes which are basically CR/LF’s
If I change that line in my code to something like you use in yours
serverCmnd.printf(“USER %s\015\012”,username.c_str());
Then the equivalent conversation Particle has with the modem is as follows
Code string: 220
connectFTPServer - stage 3
Welcome received
connectFTPServer - stage 4
617.388 AT send 15 "AT+USOWR=1,24\r\n"
617.398 AT read > 3 "\r\n@"
617.448 AT send 24 "USER robyn@nrie.com.au\r\n"
617.588 AT read + 16 "\r\n+USOWR: 1,24\r\n"
617.598 AT read OK 6 "\r\nOK\r\n"
617.929 AT read + 17 "\r\n+UUSORD: 1,50\r\n"
Socket 1: handle 1 has 50 bytes pending
This is different and shorter. And after this Particle always issues the AT Read commands allowing me to pick up the server response in my serverCmnd.read() function.
This is the only difference I can see between the two constructions, but it appears that if the first method is used then the firmware does not carry on and execute any socket reads sometimes, not all the time, which then leads to about 20% of the connections failing.
Sorry I have not got into the Particle code to trace this through but I would be reasonably certain of my results at this stage. Does it help to pin down a problem?
BTW I have changed your program to do println("USER " + username); etc and it does not fail so there is some other issue also at play here.
@pNrie @rickkas7 @peekay123 Did you guys ever get this FTP upload working without issues?
I’m looking for ways to upload a small JPG image off an SD card attached to an Electron.
Looks like you guys were almost there with the attempt above last year.
Yes had it working satisfactorily but there were still some unknowns as to why the differences mentioned in that last post were there. When I used Rick’s structure it worked
So your saying Ricks code is stable to upload images? Or did his code still give errors 20% of the time?
Were you uploading images?
Yes, that is so, although I worked his method into my own code. I don’t think the issue that I raised regarding the results obtained by the debug were ever answered, not that it really matters if one method works.
Thanks for confirming that @rickkas7 latest code was stable for FTP file uploading.
@Vitesze Looks like there is some stable FTP upload code to try to work with for uploading camera images put on an SD card via an Arduocam camera. Do you think your skilled enough to attempt to get this working for picture uploads?
Thanks for the ping. This will be a challenging but interesting thing for me to work on 
If you can get an Arduocam camera and set it up to put pictures on an SD card successful then we can try to use this code to push the pictures to an online server. There is a community here that is willing to help as long as we show some effort in figuring it out on our own 
Quite a few people have expressed interest in being able to send pictures from an Electron or Photon. A working library would be great.
This cam has a lot of good reviews.
This community has been a lot of help to me I started off half a year ago here with absolutely zero experience, and now feel quite confident with electronics and coding
What would you say are the advantages of the OV2640 over something like the OV7670 though? Seeing as how I would prefer a low-resolution camera for data purposes (and I’d probably downscale the 2640s images) the extremely low cost of the OV7670 (only about $5 through AliExpress) seems like a big advantage it has over the OV2640.
I started here with zero experience also, now I know how to code to a certain level and feel much more confident in my abilities to create new products and it feels great
The cheaper the camera the better, but you can only go so cheap until you wish you didn’t go cheap Nothing wrong with giving the cheapest camera option a try. There should be enough reviews on the net about the cam to know if it’s junk or not.