Blocks on OVH host

[pyrsmk]

Hi ;)

I've got domain host on OVH.com and I want to initialize a website by uploading it directly to the server. But it randomly blocks in the first uploaded files without errors. It just hangs. Is there a way to toggle debugging?

[Robert-W]

At the moment I have not built a hook in for this. That sounds like something that would be good to add in. Is it only for this domain that it hangs or does the same task fail on other domains as well?

If your feeling adventurous you can look in the source code, the file called ftp_push.js around the bottom and add some console logs to see how far it is getting. The main functionality of this comes down to one function at the bottom in this section here.

ftpServer.auth(credentials.username,credentials.password,function(err, res) {
      // If error, throw fatal
      if (err) { throw err; }
      grunt.log.ok(credentials.username + " successfully authenticated!");
      // Create directories specified in options.dest
      createDirectoriesForDestination(function () {
        // Normalize destionation to be used in uploadFiles
        correctedDestination = (options.dest.charAt(options.dest.length - 1) === "/" ? options.dest : options.dest += "/");
        // Upload the files and close the connection on completion
        uploadFiles(paths);
      });
    });

It basically authenticates, then tries to create any necessary directories for the destinations, and then starts uploading files. If it is not spitting out any filenames successfully uploading, then it sounds like there may be an error in creating the directories and could possibly be a permissions thing, or it's erroring out on the very first file.

Also can you tell me what the console is showing, i.e. do you see 'pyrsmk successfully authenticated' or something similar and are any other messages eventually shown or does it just hang and show nothing?

On a side note my finals are finishing up next Tuesday so i will have some time to attend to the tickets that have been piling up and there should be an update coming out for this soon :)

[pyrsmk]

Sorry for the response time ^^

It's only for this domain that the upload hangs. The FTP session is authenticated as well. It just uploads a few files and hangs on the next file.

I can debug this, but I don't know what log I can put at the bottom of your file. createDirectoriesForDestination() runs uploadFiles() just once, isn't it?

[Robert-W]

no worries. Yea it only runs once, the logs are more just a way to find specifically where it is failing but now that I know its authenticating fine and uploading a few files I know the general area where it fails and the logs are not needed. I have merged in a pull request for a keepAlive feature which may help with some session timeouts if that happens to be the culprit but it may not (merged in but not published via npm just yet, soon though).

I have seen it hang on my test's occasionally with large font files but then other co workers have tried and it worked for them so I will be exploring that a little this weekend.

Is the particular file that's failing a relatively large file or even possibly corrupted?

[pyrsmk]

Nope, it hangs on some tiny files and there are not corrupted because I can upload/run them via Filezilla.

It's really weird. Especially that it does not always hang on the same file.

[Robert-W]

That is very strange. I have some free time today so I will do some digging and see what I can come up with.

[mpiffault]

I've got exactly the same problem on OVH host. Hangs at first or second file. Edit: after diving a bit into the code, it hangs in jsftp, just after sending 'pasv' command to the server.

[mpiffault]

I used wireshark to observe the dialog between machines.

01 user *login*
02 220-Bienvenue,
03 220-
04 220-    On Vous H..berge ?
05 220-
06 220-Vous ..tes connect.. sur *servname*.
07 220 This is a private system - No anonymous login
08 331 User *login* OK. Password required
09 pass *passwd*
10 230-User *login* has group access to:  users     
11 230 OK. Current restricted directory is /
12 type I
13 200 TYPE is now 8-bit binary
14 mkd www
15 550 Can't create directory: File exists
16 mkd www/dir1
17 550 Can't create directory: File exists
18 mkd www/dir1/dir2
19 550 Can't create directory: File exists
20 mkd www/dir1/dir2/dir3
21 550 Can't create directory: File exists
22 pasv
23 227 Entering Passive Mode (213,186,33,208,82,3)
24 stor /www/dir1/dir2/dir3/dir4/s1.css
25 150 Accepted data connection
26 226-File successfully transferred
27 226 1.570 seconds (measured here), 131.02 Kbytes per second
28 pasv
29 227 Entering Passive Mode (213,186,33,208,82,88)
30 stor /www/dir1/dir2/dir3/dir4/s1.min.css
31 150 Accepted data connection
32 226-File successfully transferred
33 226 1.134 seconds (measured here), 130.05 Kbytes per second
34 pasv
35 227 Entering Passive Mode (213,186,33,208,82,174)
36 stor /www/dir1/dir2/dir3/dir4/s2.css
37 150 Accepted data connection
38 pasv
39 226-File successfully transferred
40 226 1.573 seconds (measured here), 130.76 Kbytes per second
[hangs here]

It seems that each time, it hangs when the client sends the pasv command before the server has sent back the '226-File successfully transferred' message for the previous file. For example here a typical sequence would be lines [30-35], whereas on the [36-40] seqence, l.38 the 'pasv' command comes earlier.

[Robert-W]

Hmm that's very interesting. I will have to look through some posts about OVH and see what I can dig up. It seems like I have read a lot about others having issues with OVH but not with similar errors and have came across the occasional 'Bad passive command from server' with some other plugins. (https://github.com/zonak/grunt-ftp-deploy/issues/57) although no resolution on this one. Last time I did some digging I did not come across any obvious solutions. I can try to open up a ticket with the creator of jsftp as that's the underlying ftp technology being used by this plugin and see if he is aware of any similar issues.

[Robert-W]

Thanks for the wireshark printout, that will definitely help with getting this resolved.

[Robert-W]

Created ticket with JSFTP owner to see if this is something he may be aware of. https://github.com/sergi/jsftp/issues/113

[pyrsmk]

Good to hear! I hope you'll find something with @sergi ;)

[mpiffault]

You're welcome ! I dug a bit more into tickets on jsftp especially those about multiple files problems, and you seem to use jsftp the right way ('put' following each other via callback), and i can not really understand how the bad sequence can happen (but it must be said that i'm really new to asynchronous programming). I'll try to make a capture on a working transfer to have some reference.

[Robert-W]

Thanks @mpiffault, once I hear something from the guys with the jsftp module I'll make sure to update it here.

[sergi]

Hi there,

It definitely seems that pasv is getting in the way before the 226 response comes back. The latest code in jsftp has a new debug mode using the debug library, it would be interesting to see what's the output with that enabled. Using npm link should allow you to test it. The debug mode is activated by setting the DEBUG environment variable, as in DEBUG=* node server.js.

[Robert-W]

Hi @sergi,

Thanks for responding here. I personally don't have an account to OVH to test so let me see if @pyrsmk or @mpiffault would be willing to run a test for me. Environment variables in grunt require an additional plugin which I would like to avoid so I am going to update this plugin to use jsftp 1.3.9 and give them an option to debug. I noticed setDebugMode is going to be deprecated so for the moment I will use debugMode: true in the jsftp constructor. If this is going away soon I can add the grunt-env plugin and set things up that way.

@pyrsmk @mpiffault I have just updated now and things look good, I just need to update the readme so it should be published in the next 20 minutes. If either of you have a chance could you try running this again but with debug option set to true and posting the results here or linking them in a text file. Make sure when you run this your on version 0.3.2 as that will be the version that includes this. It should look like this in you Gruntfile to run in debug mode:

ftp_push: {
  default: {
    options: {
      authKey: "serverA",
      host: "sample.server.com",
      dest: "/html/test/",
      debug: true
    },
    files: [
      {expand: true,cwd: 'test',src: ['**/*']},
      {expand: true,cwd: 'tasks',src: ['**/*'], dest: 'tasks/' }
    ]
  }
}  

NOTE: When you run in debug mode, before you post anything make sure your username and password are removed as they may show up in the console when using debug mode, so please be careful not to copy them and past them here.

[sergi]

Hi @Robert-W,

The version should actually be 1.4.0, it has just been published. I think the best way to test that would actually be to make a test with jsftp only first, not using grunt-ftp-push and just doing a put using it siilarly to how I do it in jsftp tests. Just a suggestion.

[Robert-W]

Thanks @sergi,

I'm in the process of rewriting this plugin with unit tests so Ill make a separate file to test specifically the put commands kind of how your doing with jsftp. I'll see if I can get access to an OVH account or get someone with access to one to run these tests for me and put the results of running in debug mode up here. Thanks for the help, much appreciated.

[lmeyer]

Hello,

I'm experiencing the problem on OVH FTP.

I can help you by testing what you want. Tell me how to run the tests and what is helping you to debug.

Regards,

[Robert-W]

Awesome thanks @lmeyer ,

Im gonna write some more specific tests this weekend to specifically test the jsftp portion but in the meantime if you want to try setting debug to true in the options like so:

ftp_push: {
  default: {
    options: {
      authKey: "serverA",
      host: "sample.server.com",
      dest: "/html/test/",
      debug: true
    },
    files: [
      { ... },
      { ... }
    ]
  }
}

It will run jsftp in debug mode. This will output lots of text in the console and if you can copy the last bits of it around where it fails that could be very helpful, I don't think I will need the whole output just, the stuff around the last few transfers.

I probably don't need to say this but just make sure to exclude credentials in what you post because when in debug mode, the first part of the output may contain your credentials.

[lmeyer]

Hello,

I pasted the first commands and the 3 last transfers The last one is just freezing at last line of the debug output

Hope it helps,

DEBUG:  event:connect
{}
DEBUG:  response
{
  "code": 220,
  "text": "220-Bienvenue,\n220-\n220-    On Vous Héberge ?\n220-\n220-Vous êtes connecté sur webm411.\n220 This is a private system - No anonymous login",
  "isMark": false,
  "isError": false
}
DEBUG:  response
{
  "code": 331,
  "text": "331 User XXXXXXX OK. Password required",
  "isMark": false,
  "isError": false
}
DEBUG:  user_command
"pass XXXXXXX"
DEBUG:  response
{
  "code": 230,
  "text": "230-User XXXXXXX has group access to:  users     \n230 OK. Current restricted directory is /",
  "isMark": false,
  "isError": false
}
DEBUG:  user_command
"type I"
DEBUG:  response
{
  "code": 200,
  "text": "200 TYPE is now 8-bit binary",
  "isMark": false,
  "isError": false
}
>> systemev successfully authenticated!
DEBUG:  user_command
"mkd www"
DEBUG:  response
{
  "code": 550,
  "text": "550 Can't create directory: File exists",
  "isMark": false,
  "isError": true
}

DEBUG:  user_command
"pasv"
DEBUG:  response
{
  "code": 226,
  "text": "226-File successfully transferred\n226 0.036 seconds (measured here), 18.53 Kbytes per second",
  "isMark": false,
  "isError": false
}
DEBUG:  response
{
  "code": 227,
  "text": "227 Entering Passive Mode (213,186,33,201,199,253)",
  "isMark": false,
  "isError": false
}
DEBUG:  user_command
"stor /www/wp-content/themes/test/_footer_newsletter.php"
DEBUG:  response
{
  "code": 150,
  "text": "150 Accepted data connection",
  "isMark": true,
  "isError": false
}
>> /www/wp-content/themes/test/_footer_newsletter.php transferred successfully.
DEBUG:  user_command
"pasv"
DEBUG:  response
{
  "code": 226,
  "text": "226-File successfully transferred\n226 0.340 seconds (measured here), 2.62 Kbytes per second",
  "isMark": false,
  "isError": false
}
DEBUG:  response
{
  "code": 227,
  "text": "227 Entering Passive Mode (213,186,33,201,200,11)",
  "isMark": false,
  "isError": false
}
DEBUG:  user_command
"stor /www/wp-content/themes/test/_footer_team.php"
DEBUG:  response
{
  "code": 150,
  "text": "150 Accepted data connection",
  "isMark": true,
  "isError": false
}
>> /www/wp-content/themes/test/_footer_team.php transferred successfully.
DEBUG:  user_command
"pasv"
DEBUG:  response
{
  "code": 226,
  "text": "226-File successfully transferred\n226 0.043 seconds (measured here), 35.57 Kbytes per second",
  "isMark": false,
  "isError": false
}

[lmeyer]

I'm available to do more tests

[Robert-W]

Great Thanks @lmeyer , Im going to write some more specific unit tests this weekend and I'll let you know how to run them. It will basically be a jsftp only test to try to put multiple files on to OVH server and do so in debug mode to give us some more specific details.

Hey @sergi, @lmeyer was kind enough to run my plugin in debug mode and paste the results here, is anything in there jumping out to you? I will get the jsftp only test up this weekend and see if we can get some more specific debug info in here as well.

[Robert-W]

Hey @lmeyer ,

If your still up for it I committed a new test we can try. The steps for running the test are as follows:

• Clone the repo
• npm install to install dependencies
• Edit test/jsftp/jsftpSpec.js
  • there is a defaults object at the top, change the user, pass, and host
  • there is also an iterations variable below the defaults to control how many times to put and delete the test file, since OVH does not fail on the first file I added this so you can set how many times you run the test, it's set to 5 but if it does not throw that error after 5 try incrementing to 10.

    
    var defaults = {
    username: 'user',
    password: 'pass',
    host: 'sample.server.com'
    };
    

• npm run jsftp-test

After running the test, just do the same as last time, copy the last few transfers right before it fails and paste them here. Thanks a bunch for the help on this.

[lmeyer]

Hello,

I did some tests :

1. With the test file you provided
   • Seems to be ok with, 5, 10, 20, 30, up to 80 iterations
   • Between 80 and 100 iterations i have random results (sometimes works, sometimes not)
   • With 100 iterations, i have results like

Failures:

  1) Grunt Plugin - FTP Push - JSFTP test for troublesome hosts Should push a file and remove the file multiple times successfully.
   Message:
     timeout: timed out after 5000 msec waiting for spec to complete
   Stacktrace:
     undefined

Finished in 9.005 seconds
1 test, 169 assertions, 1 failure, 0 skipped

Sometimes i have this one : i retrieve the Test.txt file on the FTP and the test is freezing

DEBUG:  response
{
  "code": 211,
  "text": "211-Extensions supported:\n EPRT\n IDLE\n MDTM\n SIZE\n REST STREAM\n MLST type*;size*;sizd*;modify*;UNIX.mode*;UNIX.uid*;UNIX.gid*;unique*;\n MLSD\n AUTH TLS\n PBSZ\n PROT\n UTF8\n TVFS\n ESTA\n PASV\n EPSV\n SPSV\n ESTP\n211 End.",
  "isMark": false,
  "isError": false
}
DEBUG:  response
{
  "code": 215,
  "text": "215 UNIX Type: L8",
  "isMark": false,
  "isError": false
}
DEBUG:  response
{
  "code": 215,
  "text": "215 UNIX Type: L8",
  "isMark": false,
  "isError": false
}
DEBUG:  response
{
  "code": 331,
  "text": "331 User XXXXXX OK. Password required",
  "isMark": false,
  "isError": false
}
DEBUG:  response
{
  "code": 331,
  "text": "331 User XXXXXX OK. Password required",
  "isMark": false,
  "isError": false
}
DEBUG:  response
{
  "code": 530,
  "text": "530 You aren't logged in",
  "isMark": false,
  "isError": true
}
DEBUG:  response
{
  "code": 530,
  "text": "530 You aren't logged in",
  "isMark": false,
  "isError": true
}

1. With a bigger file 5Ko the errors seems to be the same
2. With a bigger file 220Ko-480Ko the errors (both) happen very frequently, even with 5 iterations

Very strange that the tests need so much iterations for little files because when i tested in real conditions never more than 5 files where uploaded.

Tell me if it helps

[lmeyer]

I tried the same tests on an "older"/different OVH FTP.

Here are the resuls :

1. With you test file
   • Errors occurs from 5 iterations. I got a new message

DEBUG:  response
{
  "code": 530,
  "text": "530 You aren't logged in",
  "isMark": false,
  "isError": true
}
DEBUG:  response
{
  "code": 530,
  "text": "530 You aren't logged in",
  "isMark": false,
  "isError": true
}
DEBUG:  response
{
  "code": 421,
  "text": "421 Timeout - try typing a little faster next time",
  "isMark": false,
  "isError": true
}
DEBUG:  response
{
  "code": 421,
  "text": "421 Timeout - try typing a little faster next time",
  "isMark": false,
  "isError": true
}

• I have almost always the timeout error

Failures:

  1) Grunt Plugin - FTP Push - JSFTP test for troublesome hosts Should push a file and remove the file multiple times successfully.
   Message:
     timeout: timed out after 5000 msec waiting for spec to complete
   Stacktrace:
     undefined

1. Didn't need to try with bigger files

[Robert-W]

Thanks a lot man, I think this info will definitely be helpful.

I was hoping it would fail with 5 iterations and did not think it would need to go so high. Strange it's working now, I wonder if I need to modify the tests to push one of several files of different sizes and types and just keep iterating over the different files.

The timeout error is because jasmine-node defaults to timeouts of 5 seconds, I did not realize this initially as I thought async tests would stay running until done() was called. A quick fix for the timeout is right around line 25, beneath the describe, add jasmine.getEnv().defaultTimeoutInterval = 10000; or whatever value is needed or just do a pull, I just pushed that in now.

[Robert-W]

@sergi We have some test results, Can you check these out when you have a minute and let me know if anything sticks out.

[lmeyer]

I pulled and tried different size, iterations, and FTPs

I get same errors as before :

DEBUG:  response
{
  "code": 331,
  "text": "331 User XXXXXXX OK. Password required",
  "isMark": false,
  "isError": false
}
DEBUG:  response
{
  "code": 530,
  "text": "530 You aren't logged in",
  "isMark": false,
  "isError": true
}
DEBUG:  response
{
  "code": 530,
  "text": "530 You aren't logged in",
  "isMark": false,
  "isError": true
}

and

Failures:

  1) Grunt Plugin - FTP Push - JSFTP test for troublesome hosts Should push a file and remove the file multiple times successfully.
   Message:
     timeout: timed out after 10000 msec waiting for spec to complete
   Stacktrace:
     undefined

Regards,

[Robert-W]

Ok thanks, the timeout will have to be adjusted to be a time long enough time to complete the tests otherwise it will throw that final error but that error is not really effecting anything anyway. I wish with this version of jasmine-node they did not enforce the default timeout and let me decide when to end the test by calling done() but don't think that's possible on this version.

[Robert-W]

Closing due to inactivity