Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Can not create a remote folder #485

Open
relictMarauder opened this issue Jun 25, 2024 · 7 comments
Open

Can not create a remote folder #485

relictMarauder opened this issue Jun 25, 2024 · 7 comments

Comments

@relictMarauder
Copy link

By creating remote folder i receive the following error:

Cannot get real path for "/share/CACHEDEV1_DATA/Download/Kodi/12"

The log:

2024-06-25 08:46:19.799 . NetBox Version 24.6.0 beta (Build Build 603) (OS 10.0.22631 – Windows 10 Pro)
2024-06-25 08:46:19.800 . Configuration: NetBox 3
2024-06-25 08:46:19.800 . Log level: Debug 2
2024-06-25 08:46:19.800 . Local account: xxxxxxxx
2024-06-25 08:46:19.800 . Working directory: D:
2024-06-25 08:46:19.800 . Process ID: 42388
2024-06-25 08:46:19.800 . Ancestor processes:
2024-06-25 08:46:19.800 . Command-line:
2024-06-25 08:46:19.800 . Time zone: Current: GMT+2, Standard: GMT+1 (Mitteleuropäische Zeit), DST: GMT+2 (Mitteleuropäische Sommerzeit), DST Start: 31.03.2024, DST End: 27.10.2024
2024-06-25 08:46:19.800 . Login time: 25.06.2024 08:46:19
2024-06-25 08:46:19.800 . --------------------------------------------------------------------------
2024-06-25 08:46:19.800 . Session name: xxx/xxxxx (Modified site)
2024-06-25 08:46:19.800 . Host name: 192.168.xxx.xxx (Port: 22)
2024-06-25 08:46:19.800 . User name: admin (Password: No, Key file: Yes, Passphrase: No)
2024-06-25 08:46:19.800 . Tunnel: No
2024-06-25 08:46:19.800 . Transfer Protocol: SFTP (SCP)
2024-06-25 08:46:19.800 . Ping type: Off, Ping interval: 30 sec; Timeout: 15 sec
2024-06-25 08:46:19.800 . Disable Nagle: Yes
2024-06-25 08:46:19.800 . Proxy: None
2024-06-25 08:46:19.800 . Send buffer: 262144
2024-06-25 08:46:19.800 . Compression: No
2024-06-25 08:46:19.800 . Bypass authentication: No
2024-06-25 08:46:19.800 . Try agent: Yes; Agent forwarding: No; KI: Yes; GSSAPI: No
2024-06-25 08:46:19.800 . Ciphers: des,aes,chacha20,blowfish,3des,aesgcm,WARN,arcfour; Ssh2DES: Yes
2024-06-25 08:46:19.800 . KEX: ntru-curve25519,ecdh,dh-gex-sha1,dh-group18-sha512,dh-group17-sha512,dh-group16-sha512,dh-group15-sha512,dh-group14-sha1,rsa,WARN,dh-group1-sha1
2024-06-25 08:46:19.800 . SSH Bugs: Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto
2024-06-25 08:46:19.800 . Simple channel: Yes
2024-06-25 08:46:19.800 . Return code variable: Autodetect; Lookup user groups: On
2024-06-25 08:46:19.800 . Shell: default
2024-06-25 08:46:19.800 . EOL: LF, UTF: Off
2024-06-25 08:46:19.800 . Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: No; Follow directory symlinks: Yes
2024-06-25 08:46:19.800 . LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No; Exit code 1 is error: No
2024-06-25 08:46:19.800 . SFTP Bugs: Auto,Auto
2024-06-25 08:46:19.800 . SFTP Server: default
2024-06-25 08:46:19.800 . Local directory: default, Remote directory: /share/CACHEDEV1_DATA/Download/Kodi, Update: Yes, Cache: No
2024-06-25 08:46:19.800 . Cache directory changes: No, Permanent: No
2024-06-25 08:46:19.800 . Recycle bin: Delete to: No, Overwritten to: No, Bin path:
2024-06-25 08:46:19.800 . DST mode: Unix
2024-06-25 08:46:19.800 . --------------------------------------------------------------------------
2024-06-25 08:46:19.801 . Looking up host "192.168.xxx.xxx" for SSH connection
2024-06-25 08:46:19.801 . Connecting to 192.168.xxx.xxx port 22
2024-06-25 08:46:19.802 . Connected to 192.168.xxx.xxx
2024-06-25 08:46:19.802 . Selecting events 63 for socket 1128
2024-06-25 08:46:19.802 . Waiting for the server to continue with the initialization
2024-06-25 08:46:19.802 . Looking for incoming data
2024-06-25 08:46:19.802 . We claim version: SSH-2.0-NetBox_Far_24.6.0
2024-06-25 08:46:19.802 . Detected network event
2024-06-25 08:46:19.802 . Enumerating network events for socket 1128
2024-06-25 08:46:19.802 . Enumerated 18 network events making 18 cumulative events for socket 1128
2024-06-25 08:46:19.802 . Handling network write event on socket 1128 with error 0
2024-06-25 08:46:19.802 . Handling network connect event on socket 1128 with error 0
2024-06-25 08:46:19.802 . Connected to 192.168.xxx.xxx
2024-06-25 08:46:19.807 . Detected network event
2024-06-25 08:46:19.807 . Enumerating network events for socket 1128
2024-06-25 08:46:19.807 . Enumerated 1 network events making 1 cumulative events for socket 1128
2024-06-25 08:46:19.807 . Handling network read event on socket 1128 with error 0
2024-06-25 08:46:19.807 . Waiting for the server to continue with the initialization
2024-06-25 08:46:19.807 . Looking for incoming data
2024-06-25 08:46:19.807 . Remote version: SSH-2.0-OpenSSH_8.0
2024-06-25 08:46:19.807 . Using SSH protocol version 2
2024-06-25 08:46:19.815 . Have a known host key of type rsa2
2024-06-25 08:46:19.820 . Detected network event
2024-06-25 08:46:19.820 . Enumerating network events for socket 1128
2024-06-25 08:46:19.820 . Enumerated 1 network events making 1 cumulative events for socket 1128
2024-06-25 08:46:19.820 . Handling network read event on socket 1128 with error 0
2024-06-25 08:46:19.820 . Waiting for the server to continue with the initialization
2024-06-25 08:46:19.820 . Looking for incoming data
2024-06-25 08:46:19.821 . Doing ECDH key exchange with curve Curve25519, using hash SHA-256
2024-06-25 08:46:19.830 . Detected network event
2024-06-25 08:46:19.830 . Enumerating network events for socket 1128
2024-06-25 08:46:19.830 . Enumerated 1 network events making 1 cumulative events for socket 1128
2024-06-25 08:46:19.830 . Handling network read event on socket 1128 with error 0
2024-06-25 08:46:19.830 . Waiting for the server to continue with the initialization
2024-06-25 08:46:19.830 . Looking for incoming data
2024-06-25 08:46:19.832 . Host key fingerprint is:
2024-06-25 08:46:19.832 . ssh-rsa 2048 SHA256:xxxxxxxxxxxxxxxx
2024-06-25 08:46:19.832 . Verifying host key rxxxxxxx . Host key matches cached key
2024-06-25 08:46:19.839 . Initialised AES-256 SDCTR (AES-NI accelerated) [aes256-ctr] outbound encryption
2024-06-25 08:46:19.839 . Initialised HMAC-SHA-256 outbound MAC algorithm
2024-06-25 08:46:19.839 . Initialised AES-256 SDCTR (AES-NI accelerated) [aes256-ctr] inbound encryption
2024-06-25 08:46:19.839 . Initialised HMAC-SHA-256 inbound MAC algorithm
2024-06-25 08:46:19.839 . Detected network event
2024-06-25 08:46:19.839 . Enumerating network events for socket 1128
2024-06-25 08:46:19.839 . Enumerated 1 network events making 1 cumulative events for socket 1128
2024-06-25 08:46:19.839 . Handling network read event on socket 1128 with error 0
2024-06-25 08:46:19.839 . Waiting for the server to continue with the initialization
2024-06-25 08:46:19.839 . Looking for incoming data
2024-06-25 08:46:19.839 . Reading key file "p:\xxxxxx
2024-06-25 08:46:19.848 . Detected network event
2024-06-25 08:46:19.848 . Enumerating network events for socket 1128
2024-06-25 08:46:19.848 . Enumerated 1 network events making 1 cumulative events for socket 1128
2024-06-25 08:46:19.848 . Handling network read event on socket 1128 with error 0
2024-06-25 08:46:19.848 . Waiting for the server to continue with the initialization
2024-06-25 08:46:19.848 . Looking for incoming data
2024-06-25 08:46:19.848 . Server offered these authentication methods: publickey,password,keyboard-interactive
2024-06-25 08:46:19.848 . Offered public key
2024-06-25 08:46:19.849 . Detected network event
2024-06-25 08:46:19.849 . Enumerating network events for socket 1128
2024-06-25 08:46:19.849 . Enumerated 1 network events making 1 cumulative events for socket 1128
2024-06-25 08:46:19.849 . Handling network read event on socket 1128 with error 0
2024-06-25 08:46:19.849 . Waiting for the server to continue with the initialization
2024-06-25 08:46:19.849 . Looking for incoming data
2024-06-25 08:46:19.849 . Offer of public key accepted
2024-06-25 08:46:19.849 ! Using username "admin".Authenticating with public key "imported-openssh-key"
2024-06-25 08:46:19.854 . Sent public key signature
2024-06-25 08:46:19.865 . Detected network event
2024-06-25 08:46:19.865 . Enumerating network events for socket 1128
2024-06-25 08:46:19.865 . Enumerated 1 network events making 1 cumulative events for socket 1128
2024-06-25 08:46:19.865 . Handling network read event on socket 1128 with error 0
2024-06-25 08:46:19.865 . Waiting for the server to continue with the initialization
2024-06-25 08:46:19.865 . Looking for incoming data
2024-06-25 08:46:19.865 . Access granted
2024-06-25 08:46:19.865 . Opening main session channel
2024-06-25 08:46:19.872 . Detected network event
2024-06-25 08:46:19.872 . Enumerating network events for socket 1128
2024-06-25 08:46:19.872 . Enumerated 1 network events making 1 cumulative events for socket 1128
2024-06-25 08:46:19.872 . Handling network read event on socket 1128 with error 0
2024-06-25 08:46:19.872 . Waiting for the server to continue with the initialization
2024-06-25 08:46:19.872 . Looking for incoming data
2024-06-25 08:46:19.872 . Remote debug message: /root/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
2024-06-25 08:46:19.918 . Detected network event
2024-06-25 08:46:19.918 . Enumerating network events for socket 1128
2024-06-25 08:46:19.918 . Enumerated 1 network events making 1 cumulative events for socket 1128
2024-06-25 08:46:19.918 . Handling network read event on socket 1128 with error 0
2024-06-25 08:46:19.918 . Waiting for the server to continue with the initialization
2024-06-25 08:46:19.918 . Looking for incoming data
2024-06-25 08:46:19.918 . Remote debug message: /root/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
2024-06-25 08:46:19.918 . Opened main channel
2024-06-25 08:46:19.918 . Detected network event
2024-06-25 08:46:19.918 . Enumerating network events for socket 1128
2024-06-25 08:46:19.918 . Enumerated 1 network events making 1 cumulative events for socket 1128
2024-06-25 08:46:19.918 . Handling network read event on socket 1128 with error 0
2024-06-25 08:46:19.918 . Waiting for the server to continue with the initialization
2024-06-25 08:46:19.918 . Looking for incoming data
2024-06-25 08:46:19.918 . Started a shell/command
2024-06-25 08:46:19.919 . --------------------------------------------------------------------------
2024-06-25 08:46:19.919 . Using SFTP protocol.
2024-06-25 08:46:19.919 . Doing startup conversation with host.
2024-06-25 08:46:19.919 . Skipped packets
2024-06-25 08:46:19.919 > Type: SSH_FXP_INIT, Size: 5, Number: -1
2024-06-25 08:46:19.919 > 01,00,00,00,06,
2024-06-25 08:46:19.919 . Sent 9 bytes
2024-06-25 08:46:19.919 . There are 0 bytes remaining in the send buffer
2024-06-25 08:46:19.919 . Waiting for another 4 bytes
2024-06-25 08:46:19.919 . Looking for incoming data
2024-06-25 08:46:19.958 . Detected network event
2024-06-25 08:46:19.958 . Enumerating network events for socket 1128
2024-06-25 08:46:19.958 . Enumerated 1 network events making 1 cumulative events for socket 1128
2024-06-25 08:46:19.958 . Handling network read event on socket 1128 with error 0
2024-06-25 08:46:19.958 . Waiting for another 4 bytes
2024-06-25 08:46:19.958 . Looking for incoming data
2024-06-25 08:46:19.958 . Received 183 bytes
2024-06-25 08:46:19.958 . Read 4 bytes (179 pending)
2024-06-25 08:46:19.958 . Read 179 bytes (0 pending)
2024-06-25 08:46:19.958 . Skipped packets
2024-06-25 08:46:19.958 < Type: SSH_FXP_VERSION, Size: 179, Number: -1
2024-06-25 08:46:19.958 < 02,00,00,00,03,00,00,00,18,70,6F,73,69,78,2D,72,65,6E,61,6D,65,40,6F,70,65,
2024-06-25 08:46:19.958 < 6E,73,73,68,2E,63,6F,6D,00,00,00,01,31,00,00,00,13,73,74,61,74,76,66,73,40,
2024-06-25 08:46:19.958 < 6F,70,65,6E,73,73,68,2E,63,6F,6D,00,00,00,01,32,00,00,00,14,66,73,74,61,74,
2024-06-25 08:46:19.958 < 76,66,73,40,6F,70,65,6E,73,73,68,2E,63,6F,6D,00,00,00,01,32,00,00,00,14,68,
2024-06-25 08:46:19.958 < 61,72,64,6C,69,6E,6B,40,6F,70,65,6E,73,73,68,2E,63,6F,6D,00,00,00,01,31,00,
2024-06-25 08:46:19.958 < 00,00,11,66,73,79,6E,63,40,6F,70,65,6E,73,73,68,2E,63,6F,6D,00,00,00,01,31,
2024-06-25 08:46:19.958 < 00,00,00,14,6C,73,65,74,73,74,61,74,40,6F,70,65,6E,73,73,68,2E,63,6F,6D,00,
2024-06-25 08:46:19.958 < 00,00,01,31,
2024-06-25 08:46:19.958 . SFTP version 3 negotiated.
2024-06-25 08:46:19.958 . Supports extension posix-rename@openssh.com="1"
2024-06-25 08:46:19.958 . Supports statvfs@openssh.com extension version 2
2024-06-25 08:46:19.958 . Unknown server extension fstatvfs@openssh.com="2"
2024-06-25 08:46:19.958 . Supports hardlink@openssh.com extension version 1
2024-06-25 08:46:19.958 . Unknown server extension fsync@openssh.com="1"
2024-06-25 08:46:19.958 . Unknown server extension lsetstat@openssh.com="1"
2024-06-25 08:46:19.958 . We believe the server has signed timestamps bug
2024-06-25 08:46:19.958 . We will not use UTF-8 strings as configured
2024-06-25 08:46:19.958 . Limiting packet size to OpenSSH sftp-server limit of 262148 bytes
2024-06-25 08:46:19.958 . Changing directory to "/share/CACHEDEV1_DATA/Download/Kodi".
2024-06-25 08:46:19.958 . Getting real path for '/share/CACHEDEV1_DATA/Download/Kodi'
2024-06-25 08:46:19.958 . Skipped packets
2024-06-25 08:46:19.958 > Type: SSH_FXP_REALPATH, Size: 44, Number: 922896
2024-06-25 08:46:19.958 > 10,00,0E,15,10,00,00,00,23,2F,73,68,61,72,65,2F,43,41,43,48,45,44,45,56,31,
2024-06-25 08:46:19.958 > 5F,44,41,54,41,2F,44,6F,77,6E,6C,6F,61,64,2F,4B,6F,64,69,
2024-06-25 08:46:19.958 . Sent 48 bytes
2024-06-25 08:46:19.958 . There are 0 bytes remaining in the send buffer
2024-06-25 08:46:19.958 . Waiting for another 4 bytes
2024-06-25 08:46:19.958 . Looking for incoming data
2024-06-25 08:46:19.959 . Detected network event
2024-06-25 08:46:19.959 . Enumerating network events for socket 1128
2024-06-25 08:46:19.959 . Enumerated 1 network events making 1 cumulative events for socket 1128
2024-06-25 08:46:19.959 . Handling network read event on socket 1128 with error 0
2024-06-25 08:46:19.959 . Waiting for another 4 bytes
2024-06-25 08:46:19.959 . Looking for incoming data
2024-06-25 08:46:19.959 . Received 95 bytes
2024-06-25 08:46:19.959 . Read 4 bytes (91 pending)
2024-06-25 08:46:19.959 . Read 91 bytes (0 pending)
2024-06-25 08:46:19.959 . Skipped packets
2024-06-25 08:46:19.959 < Type: SSH_FXP_NAME, Size: 91, Number: 922896
2024-06-25 08:46:19.959 < 68,00,0E,15,10,00,00,00,01,00,00,00,23,2F,73,68,61,72,65,2F,43,41,43,48,45,
2024-06-25 08:46:19.959 < 44,45,56,31,5F,44,41,54,41,2F,44,6F,77,6E,6C,6F,61,64,2F,4B,6F,64,69,00,00,
2024-06-25 08:46:19.959 < 00,23,2F,73,68,61,72,65,2F,43,41,43,48,45,44,45,56,31,5F,44,41,54,41,2F,44,
2024-06-25 08:46:19.959 < 6F,77,6E,6C,6F,61,64,2F,4B,6F,64,69,00,00,00,00,
2024-06-25 08:46:19.959 . Real path is '/share/CACHEDEV1_DATA/Download/Kodi'

2024-06-25 08:43:54.709 . Creating directory "12".
2024-06-25 08:43:54.709 . Getting real path for '/share/CACHEDEV1_DATA/Download/Kodi/12'
2024-06-25 08:43:54.709 . Skipped packets
2024-06-25 08:43:54.709 > Type: SSH_FXP_REALPATH, Size: 47, Number: 922640
2024-06-25 08:43:54.709 > 10,00,0E,14,10,00,00,00,26,2F,73,68,61,72,65,2F,43,41,43,48,45,44,45,56,31,
2024-06-25 08:43:54.709 > 5F,44,41,54,41,2F,44,6F,77,6E,6C,6F,61,64,2F,4B,6F,64,69,2F,31,32,
2024-06-25 08:43:54.709 . Sent 51 bytes
2024-06-25 08:43:54.709 . There are 0 bytes remaining in the send buffer
2024-06-25 08:43:54.709 . Waiting for another 4 bytes
2024-06-25 08:43:54.709 . Looking for incoming data
2024-06-25 08:43:54.710 . Detected network event
2024-06-25 08:43:54.710 . Enumerating network events for socket 1452
2024-06-25 08:43:54.710 . Enumerated 1 network events making 1 cumulative events for socket 1452
2024-06-25 08:43:54.710 . Handling network read event on socket 1452 with error 0
2024-06-25 08:43:54.710 . Waiting for another 4 bytes
2024-06-25 08:43:54.710 . Looking for incoming data
2024-06-25 08:43:54.710 . Received 33 bytes
2024-06-25 08:43:54.710 . Read 4 bytes (29 pending)
2024-06-25 08:43:54.710 . Read 29 bytes (0 pending)
2024-06-25 08:43:54.710 . Skipped packets
2024-06-25 08:43:54.710 < Type: SSH_FXP_STATUS, Size: 29, Number: 922640
2024-06-25 08:43:54.710 < 65,00,0E,14,10,00,00,00,02,00,00,00,0C,4E,6F,20,73,75,63,68,20,66,69,6C,65,
2024-06-25 08:43:54.710 < 00,00,00,00,
2024-06-25 08:43:54.710 < Status code: 2, Message: 922640, Server: No such file, Language:
@ssvine
Copy link
Contributor

ssvine commented Jun 26, 2024

Seems unrelated to NetBox. SSH_FXP_STATUS - it's the response from the sftp server. Try to check the remote end

@relictMarauder
Copy link
Author

relictMarauder commented Jun 26, 2024 •
edited
Loading

The are no such problems with old versions of NetBox(2.4.x) and WinScp

Log from WinSCP:

. 2024-06-26 19:50:58.275 WinSCP Version 6.3.4 (Build 14955 2024-06-17) (OS 10.0.22631 – Windows 10 Enterprise)
. 2024-06-26 19:50:58.275 Configuration: HKCU\Software\Martin Prikryl\WinSCP 2\
. 2024-06-26 19:50:58.275 Log level: Debug 2
. 2024-06-26 19:50:58.275 Local account: RELICT-PC\Relict
. 2024-06-26 19:50:58.275 Working directory: C:\Program Files (x86)\WinSCP
. 2024-06-26 19:50:58.275 Process ID: 52488
. 2024-06-26 19:50:58.286 Ancestor processes: explorer, ...
. 2024-06-26 19:50:58.286 Command-line: "C:\Program Files (x86)\WinSCP\WinSCP.exe" 
. 2024-06-26 19:50:58.286 Time zone: Current: GMT+2, Standard: GMT+1 (Mitteleuropäische Zeit), DST: GMT+2 (Mitteleuropäische Sommerzeit), DST Start: 31.03.2024, DST End: 27.10.2024
. 2024-06-26 19:50:58.286 Login time: Mittwoch, 26. Juni 2024 19:50:58
. 2024-06-26 19:50:58.286 --------------------------------------------------------------------------
. 2024-06-26 19:50:58.286 Session name: admi@192.168.xxx.xxx (Ad-Hoc site)
. 2024-06-26 19:50:58.286 Host name: 192.168.xxx.xxx (Port: 22)
. 2024-06-26 19:50:58.286 User name: admi (Password: No, Key file: Yes, Passphrase: No)
. 2024-06-26 19:50:58.286 Tunnel: No
. 2024-06-26 19:50:58.286 Transfer Protocol: SFTP (SCP)
. 2024-06-26 19:50:58.286 Ping type: Off, Ping interval: 30 sec; Timeout: 15 sec
. 2024-06-26 19:50:58.286 Disable Nagle: No
. 2024-06-26 19:50:58.286 Proxy: None
. 2024-06-26 19:50:58.286 Send buffer: 262144
. 2024-06-26 19:50:58.286 Compression: No
. 2024-06-26 19:50:58.286 Bypass authentication: No
. 2024-06-26 19:50:58.286 Try agent: Yes; Agent forwarding: No; KI: Yes; GSSAPI: Yes
. 2024-06-26 19:50:58.286 GSSAPI: KEX: No; Forwarding: No; Libs: gssapi32,sspi,custom; Custom: 
. 2024-06-26 19:50:58.286 Ciphers: aes,chacha20,aesgcm,3des,WARN,des,blowfish,arcfour; Ssh2DES: No
. 2024-06-26 19:50:58.286 KEX: ntru-curve25519,ecdh,dh-gex-sha1,dh-group18-sha512,dh-group17-sha512,dh-group16-sha512,dh-group15-sha512,dh-group14-sha1,rsa,WARN,dh-group1-sha1
. 2024-06-26 19:50:58.286 SSH Bugs: Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto
. 2024-06-26 19:50:58.286 Simple channel: Yes
. 2024-06-26 19:50:58.286 Return code variable: Autodetect; Lookup user groups: Auto
. 2024-06-26 19:50:58.286 Shell: default
. 2024-06-26 19:50:58.286 EOL: LF, UTF: Auto
. 2024-06-26 19:50:58.286 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes; Follow directory symlinks: No
. 2024-06-26 19:50:58.286 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No; Exit code 1 is error: No
. 2024-06-26 19:50:58.286 SFTP Bugs: Auto,Auto
. 2024-06-26 19:50:58.286 SFTP Server: default
. 2024-06-26 19:50:58.286 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2024-06-26 19:50:58.286 Cache directory changes: Yes, Permanent: Yes
. 2024-06-26 19:50:58.286 Recycle bin: Delete to: No, Overwritten to: No, Bin path: 
. 2024-06-26 19:50:58.286 DST mode: Unix
. 2024-06-26 19:50:58.286 --------------------------------------------------------------------------
. 2024-06-26 19:50:58.311 Looking up host "192.168.xxx.xxx" for SSH connection
. 2024-06-26 19:50:58.311 Connecting to 192.168.xxx.xxx port 22
. 2024-06-26 19:50:58.311 Connected to 192.168.xxx.xxx
. 2024-06-26 19:50:58.311 Selecting events 63 for socket 3036
. 2024-06-26 19:50:58.339 Waiting for the server to continue with the initialization
. 2024-06-26 19:50:58.339 Looking for incoming data
. 2024-06-26 19:50:58.339 Looking for network events
. 2024-06-26 19:50:58.339 We claim version: SSH-2.0-WinSCP_release_6.3.4
. 2024-06-26 19:50:58.339 Detected network event
. 2024-06-26 19:50:58.339 Enumerating network events for socket 3036
. 2024-06-26 19:50:58.339 Enumerated 19 network events making 19 cumulative events for socket 3036
. 2024-06-26 19:50:58.339 Handling network write event on socket 3036 with error 0
. 2024-06-26 19:50:58.339 Handling network connect event on socket 3036 with error 0
. 2024-06-26 19:50:58.339 Connected to 192.168.xxx.xxx
. 2024-06-26 19:50:58.339 Handling network read event on socket 3036 with error 0
. 2024-06-26 19:50:58.339 Waiting for the server to continue with the initialization
. 2024-06-26 19:50:58.339 Looking for incoming data
. 2024-06-26 19:50:58.339 Looking for network events
. 2024-06-26 19:50:58.339 Remote version: SSH-2.0-OpenSSH_8.0
. 2024-06-26 19:50:58.339 Using SSH protocol version 2
. 2024-06-26 19:50:58.339 Have a known host key of type rsa2
. 2024-06-26 19:50:58.339 Detected network event
. 2024-06-26 19:50:58.339 Enumerating network events for socket 3036
. 2024-06-26 19:50:58.339 Enumerated 1 network events making 1 cumulative events for socket 3036
. 2024-06-26 19:50:58.339 Handling network read event on socket 3036 with error 0
. 2024-06-26 19:50:58.339 Waiting for the server to continue with the initialization
. 2024-06-26 19:50:58.339 Looking for incoming data
. 2024-06-26 19:50:58.339 Looking for network events
. 2024-06-26 19:50:58.343 Doing ECDH key exchange with curve Curve25519, using hash SHA-256
. 2024-06-26 19:50:58.352 Detected network event
. 2024-06-26 19:50:58.352 Enumerating network events for socket 3036
. 2024-06-26 19:50:58.352 Enumerated 1 network events making 1 cumulative events for socket 3036
. 2024-06-26 19:50:58.352 Handling network read event on socket 3036 with error 0
. 2024-06-26 19:50:58.352 Waiting for the server to continue with the initialization
. 2024-06-26 19:50:58.352 Looking for incoming data
. 2024-06-26 19:50:58.352 Looking for network events
....

. 2024-06-26 19:51:32.882 Creating directory "12".
. 2024-06-26 19:51:32.882 Canonifying: "12"
. 2024-06-26 19:51:32.882 Getting real path for '/share/CACHEDEV1_DATA/Download/Kodi/12'
> 2024-06-26 19:51:32.882 Type: SSH_FXP_REALPATH, Size: 47, Number: 23568
> 2024-06-26 19:51:32.882 10,00,00,5C,10,00,00,00,26,2F,73,68,61,72,65,2F,43,41,43,48,45,44,45,56,31,
> 2024-06-26 19:51:32.882 5F,44,41,54,41,2F,44,6F,77,6E,6C,6F,61,64,2F,4B,6F,64,69,2F,31,32,
. 2024-06-26 19:51:32.882 Sent 51 bytes
. 2024-06-26 19:51:32.882 There are 0 bytes remaining in the send buffer
. 2024-06-26 19:51:32.882 Looking for network events
. 2024-06-26 19:51:32.888 Timeout waiting for network events
. 2024-06-26 19:51:32.888 Read 4 bytes (24 pending)
. 2024-06-26 19:51:32.888 Read 24 bytes (0 pending)
< 2024-06-26 19:51:32.888 Type: SSH_FXP_STATUS, Size: 24, Number: 23044
< 2024-06-26 19:51:32.888 65,00,00,5A,04,00,00,00,00,00,00,00,07,53,75,63,63,65,73,73,00,00,00,00,
. 2024-06-26 19:51:32.888 Discarding reserved response
. 2024-06-26 19:51:32.888 Waiting for another 4 bytes
. 2024-06-26 19:51:32.888 Looking for incoming data
. 2024-06-26 19:51:32.888 Looking for network events
. 2024-06-26 19:51:32.888 Detected network event
. 2024-06-26 19:51:32.888 Enumerating network events for socket 2096
. 2024-06-26 19:51:32.888 Enumerated 1 network events making 1 cumulative events for socket 2096
. 2024-06-26 19:51:32.888 Handling network read event on socket 2096 with error 0
. 2024-06-26 19:51:32.888 Waiting for another 4 bytes
. 2024-06-26 19:51:32.888 Looking for incoming data
. 2024-06-26 19:51:32.888 Looking for network events
. 2024-06-26 19:51:32.888 Received 33 bytes
. 2024-06-26 19:51:32.888 Timeout waiting for network events
. 2024-06-26 19:51:32.888 Read 4 bytes (29 pending)
. 2024-06-26 19:51:32.888 Read 29 bytes (0 pending)
< 2024-06-26 19:51:32.888 Type: SSH_FXP_STATUS, Size: 29, Number: 23568
< 2024-06-26 19:51:32.888 65,00,00,5C,10,00,00,00,02,00,00,00,0C,4E,6F,20,73,75,63,68,20,66,69,6C,65,
< 2024-06-26 19:51:32.888 00,00,00,00,
< 2024-06-26 19:51:32.888 Status code: 2, Message: 23568, Server: No such file, Language:  
. 2024-06-26 19:51:32.888 Getting real path for '/share/CACHEDEV1_DATA/Download/Kodi/'
> 2024-06-26 19:51:32.888 Type: SSH_FXP_REALPATH, Size: 45, Number: 23824
> 2024-06-26 19:51:32.888 10,00,00,5D,10,00,00,00,24,2F,73,68,61,72,65,2F,43,41,43,48,45,44,45,56,31,
> 2024-06-26 19:51:32.888 5F,44,41,54,41,2F,44,6F,77,6E,6C,6F,61,64,2F,4B,6F,64,69,2F,
. 2024-06-26 19:51:32.888 Sent 49 bytes
. 2024-06-26 19:51:32.888 There are 0 bytes remaining in the send buffer
. 2024-06-26 19:51:32.888 Looking for network events
. 2024-06-26 19:51:32.888 Timeout waiting for network events
. 2024-06-26 19:51:32.888 Waiting for another 4 bytes
. 2024-06-26 19:51:32.888 Looking for incoming data
. 2024-06-26 19:51:32.888 Looking for network events
. 2024-06-26 19:51:32.888 Detected network event
. 2024-06-26 19:51:32.888 Enumerating network events for socket 2096
. 2024-06-26 19:51:32.888 Enumerated 1 network events making 1 cumulative events for socket 2096
. 2024-06-26 19:51:32.888 Handling network read event on socket 2096 with error 0
. 2024-06-26 19:51:32.888 Waiting for another 4 bytes
. 2024-06-26 19:51:32.888 Looking for incoming data
. 2024-06-26 19:51:32.888 Looking for network events
. 2024-06-26 19:51:32.888 Received 95 bytes
. 2024-06-26 19:51:32.888 Timeout waiting for network events
. 2024-06-26 19:51:32.888 Read 4 bytes (91 pending)
. 2024-06-26 19:51:32.888 Read 91 bytes (0 pending)
< 2024-06-26 19:51:32.888 Type: SSH_FXP_NAME, Size: 91, Number: 23824
< 2024-06-26 19:51:32.888 68,00,00,5D,10,00,00,00,01,00,00,00,23,2F,73,68,61,72,65,2F,43,41,43,48,45,
< 2024-06-26 19:51:32.888 44,45,56,31,5F,44,41,54,41,2F,44,6F,77,6E,6C,6F,61,64,2F,4B,6F,64,69,00,00,
< 2024-06-26 19:51:32.888 00,23,2F,73,68,61,72,65,2F,43,41,43,48,45,44,45,56,31,5F,44,41,54,41,2F,44,
< 2024-06-26 19:51:32.888 6F,77,6E,6C,6F,61,64,2F,4B,6F,64,69,00,00,00,00,
. 2024-06-26 19:51:32.888 Real path is '/share/CACHEDEV1_DATA/Download/Kodi'
. 2024-06-26 19:51:32.888 Canonified: "/share/CACHEDEV1_DATA/Download/Kodi/12"
> 2024-06-26 19:51:32.888 Type: SSH_FXP_MKDIR, Size: 51, Number: 23310
> 2024-06-26 19:51:32.888 0E,00,00,5B,0E,00,00,00,26,2F,73,68,61,72,65,2F,43,41,43,48,45,44,45,56,31,
> 2024-06-26 19:51:32.888 5F,44,41,54,41,2F,44,6F,77,6E,6C,6F,61,64,2F,4B,6F,64,69,2F,31,32,00,00,00,
> 2024-06-26 19:51:32.888 00,

@ssvine
Copy link
Contributor

ssvine commented Jun 26, 2024

Can you provide the full log? The first one is creepy enough with time going back (you create folder at 08:43:54.709 before opening the connection at 08:46:19.918). Also, users are different.

Does this problem occur in any directories, e.g. in /tmp, or only in /share/CACHEDEV1_DATA/Download/Kodi? Does your path have any symlinks? You can try to set [x] Resolve symbolic links option.

For now I cannot reproduce your problem, so it's better to provide a minimal reproducible example.

@relictMarauder
Copy link
Author

Thank you for analyse.
I can reproduce same behavior for all folders
hier is full log for one folder in /tmp by trying to create a subfloder over NetBox -> folder can't be created
net-box.log
hier is full log for one folder in /tmp by trying to create a subfloder over WinScp(same user/server as for NetBox) -> folder can be created
the are not
winscp.log
synmlinks in whole path

@ssvine
Copy link
Contributor

ssvine commented Jun 27, 2024

Still cannot reproduce the problem. Does NetBox show any error messages?

Have you tried to reproduce the problem on other servers?

Have you tried to use different windows machine with fresh far installation when connecting to the problematic server?

Can you export netbox session and show it here (use F5 key from the session list)?

@relictMarauder
Copy link
Author

relictMarauder commented Jun 27, 2024 •
edited
Loading

Hi i looked deeply in differences between WinScp and NetBox at places which are envolwed in this use case and found this place:

WinScp(https://github.com/winscp/winscp/blob/d7286a7ae7d7911c2e5dc41c47f2b93c73d905d2/source/core/Terminal.cpp):

void __fastcall TTerminal::DoCreateDirectory(const UnicodeString & DirName, bool Encrypt)
{
  TRetryOperationLoop RetryLoop(this);
  do
  {
    TMkdirSessionAction Action(ActionLog, AbsolutePath(DirName, true));
    try
    {
      DebugAssert(FFileSystem);
      FFileSystem->CreateDirectory(DirName, Encrypt);
    }
    catch(Exception & E)
    {
      RetryLoop.Error(E, Action, FMTLOAD(CREATE_DIR_ERROR, (DirName)));
    }
  }
  while (RetryLoop.Retry());
}

NetBox(https://github.com/michaellukashov/Far-NetBox/blob/7c7a41c04e98151c568639f3c76cf0ecda71ce7f/src/core/Terminal.cpp):

void TTerminal::DoCreateDirectory(const UnicodeString & ADirName, bool Encrypt)
{
  TRetryOperationLoop RetryLoop(this);
  do
  {
    TMkdirSessionAction Action(GetActionLog(), GetAbsolutePath(ADirName, false));
    try
    {
      DebugAssert(FFileSystem);
      // DEBUG_PRINTF("ADirName: %s", ADirName);
      FFileSystem->CreateDirectory(ADirName, Encrypt);
    }
    catch(Exception & E)
    {
      RetryLoop.Error(E, Action, FMTLOAD(CREATE_DIR_ERROR, ADirName));
    }
  }
  while (RetryLoop.Retry());
}

The difference is in second parameter in the call of AbsolutePath function. NetScp use 'false' and WinScp use 'true'

This difference seems to produce the exception by calling GetAbsolutePath, becouse the ADirName is not exist at this time.

After i change this param from "false" to "true" this problem could not be reproduced any more.

I hope this helps.

nextbox-session:

xxxxx-qnap@admin.netbox.txt

@ssvine
Copy link
Contributor

ssvine commented Jun 27, 2024

Thanks, I'll check your findings

michaellukashov added a commit that referenced this issue Jun 29, 2024
@michaellukashov
Bugfix: Can not create a remote folder - Issue #485
1fbae06 
#485
michaellukashov added a commit that referenced this issue Jun 29, 2024
@michaellukashov
Merge branch 'main' into far3-dev-tests
29f27dc 
* main:
  upd ChangeLog
  Bugfix: Can not create a remote folder - Issue #485
  sync with WinSCP: rename TCustomFileSystem::GetAbsolutePath -> TCustomFileSystem::AbsolutePath
  sync with WinSCP: rename TTerminal::GetAbsolutePath -> TTerminal::AbsolutePath
  clarify .ppk file prompt: add (.ppk)
  upd NetBox version info
  upd OpenSSL version info
  OpenSSL: NetBox patches
  OpenSSL: upd to 3.3.1
  bump version to 24.6.0.603
  upd OpenSSL version info
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@relictMarauder @ssvine