#1069 read error on PUT file operation for HTTP_UPLOAD
Reporter
Alberto
Owner
Zash
Created
Updated
Stars
★ (1)
Tags
Status-CantFix
Type-Defect
Priority-Medium
Alberto
on
What steps will reproduce the problem?
1. use the latest MOD_HTTP_UPLOAD.lua on Prosody 0.9.7
2. use a mobile client (i.e. Xabber, Conversations) to send a file during XMPP session
3. check Prosody's "debug" output in logfile
What is the expected output?
The desired file should be uploaded to the server
What do you see instead?
File progress reaches 100% transferred, then "failed" is shown
What version of the product are you using? On what operating system?
Prosody 0.9.7 on AstLinux 1.2.2 (linux kernel 3.2.66)
Please provide any additional information below.
Jan 14 19:45:38 c2s85204f8 debug Given upload slot "d7751183-495e-4a0f-83
3b-57c4e33af7cf/IMG_20180106_194016.jpg"
Jan 14 19:45:38 socket debug server.lua: auto-starting ssl negotiation...
Jan 14 19:45:38 socket debug server.lua: attempting to start tls on tcp{clien
t}: 0x858983c
Jan 14 19:45:38 socket debug server.lua: accepted new client connection from
192.168.1.254:57088 to 5281
Jan 14 19:45:39 socket debug server.lua: ssl handshake done
Jan 14 19:45:39 socket debug server.lua: client 192.168.1.254:57088 read erro
r: closed
Jan 14 19:45:39 socket debug server.lua: closed client handler and removed so
cket from list
Zash
on
Please include the output of `prosodyctl about` and whether libevent is enabled.
Not using libevent rules out #583.
This could be a certificate validation issue, does the clients say anything about that? Check their debug logs, if they have any.
You could also try disabling HTTPS and see if the same thing happens, by setting https_ports = { }
Alberto
on
Analysing client's log (Xabber for Android) in details, I see that the client starts a PUT operation with the correct URL (e.g. https://domain.tld/upload/<slot>/file.ext) but is returned a web page in which it's written "404 Not Found - Whatever you were looking for is not here, Where did you put it?"
On the server, no files are actually created in the /upload area, just the folder with the given slot name.
To test Prosody's http server efficiency, I manually created a small textfile in a known /upload subfolder, that I can regulary display on a browser using the right URL (e.g. https://domain.tld/upload/test/test.txt)
It seems the problem arises in file creation, but I don't understand why the server can create the folder but not the file.
Zash
on
The directory is created when the slot is handed out, not when the file is uploaded, so this make sense.
Are any options described in https://prosody.im/doc/http set?
Is mod_http_upload loaded globally / on multiple VirtualHosts?
(Please delete the domain shown in http_external_url I forgot clean)
Zash
on
If you have mod_http_upload loaded globally with many VirtualHosts that get the same URLs (either because same http_host or same http_external_url etc) then the requests may end up routed to a different instance than the one that issued the upload slot, and you get this behavior.
Either alter the URLs so they are different for each host, or limit mod_http_upload to a single host, or make it a Component.
I don't think we can do much about this behaviour, since it is a design issue, not a code issue. There are tweaks in place that are supposed to help, but they don't work.
Changes
tags Status-CantFix
Johannes
on
What steps will reproduce the problem?
1. use the latest MOD_HTTP_UPLOAD.lua on Prosody 0.10 on debian 8.
2. use Gajim as client
3. check Prosody's "debug" output in logfile
4. error message given by Gajim will lead also to problem
What is the expected output?
The desired file should be uploaded to the server
What do you see instead?
File progress reaches 100% transferred, then "failed" message is shown
debug log
Mar 20 20:05:24 c2s86b6500 debug Handled 46 incoming stanzas
Mar 20 20:05:24 c2s86b6500 debug Received[c2s]: <iq id='d5d8bbea-b1fd-4fa0-8410-dea2e7886e1f' type='get' to='upload.mydomain.com' from='test@mydomain.com/gajim.GJW8OJLV'>
Mar 20 20:05:24 c2s86b6500 debug Given upload slot "6XX1QHT79KGYSwtV/PCN.pdf"
Mar 20 20:05:24 c2s86b6500 debug #queue = 1
Mar 20 20:05:24 c2s86b6500 debug Queuing <r> (in a moment)
Mar 20 20:05:24 c2s86b6500 debug Sending <r> (inside timer, before send)
Mar 20 20:05:24 c2s86b6500 debug Sending <r> (inside timer, after send)
Mar 20 20:05:24 c2s86b6500 debug Received[c2s]: <r xmlns='urn:xmpp:sm:3'>
Mar 20 20:05:24 jabber.yorktondigital.ca:smacks debug Received ack request, acking for 46
On the server, no files are actually created in the /upload area, just the folder with the given slot name.
Testing further especially looking into issue 583 mentioned in this issue, I can confirm the following:
use_libevent = true
using network_default_read_size ="*a"
will not solve the issue, file is still not placed in /upload folder but the error message from Gajim has changed to: "Upload Error [ WinError 10060] a connection attempt failed because of the connection party did not properly respond after a periode of time or connecting host failed to respond"
This new error message is due to using "network_default_read_size ="*a"
DISABLING libevent DID solve the problem and uploads are working, files were placed into /upload folder, links were placed in message
Also disabling network_default_read_size made no difference, http_upload working as described above.
In my situation: prosody 0.10 from debian8 repository with last mod_http_upload AND disabling libevent in configuration solved http upload problem.
What steps will reproduce the problem? 1. use the latest MOD_HTTP_UPLOAD.lua on Prosody 0.9.7 2. use a mobile client (i.e. Xabber, Conversations) to send a file during XMPP session 3. check Prosody's "debug" output in logfile What is the expected output? The desired file should be uploaded to the server What do you see instead? File progress reaches 100% transferred, then "failed" is shown What version of the product are you using? On what operating system? Prosody 0.9.7 on AstLinux 1.2.2 (linux kernel 3.2.66) Please provide any additional information below. Jan 14 19:45:38 c2s85204f8 debug Given upload slot "d7751183-495e-4a0f-83 3b-57c4e33af7cf/IMG_20180106_194016.jpg" Jan 14 19:45:38 socket debug server.lua: auto-starting ssl negotiation... Jan 14 19:45:38 socket debug server.lua: attempting to start tls on tcp{clien t}: 0x858983c Jan 14 19:45:38 socket debug server.lua: accepted new client connection from 192.168.1.254:57088 to 5281 Jan 14 19:45:39 socket debug server.lua: ssl handshake done Jan 14 19:45:39 socket debug server.lua: client 192.168.1.254:57088 read erro r: closed Jan 14 19:45:39 socket debug server.lua: closed client handler and removed so cket from list
Please include the output of `prosodyctl about` and whether libevent is enabled.
Changesasterisk ~ # prosodyctl about Prosody 0.9.7 # Prosody directories Data directory: /etc/prosody/data Plugin directory: /usr/lib/prosody/modules/ Config directory: /etc/prosody Source directory: /usr/lib/prosody # Lua environment Lua version: Lua 5.1 Lua module search paths: /usr/lib/prosody/?.lua /usr/share/lua/?.lua /usr/share/lua/?/init.lua /usr/lib/lua/?.lua /usr/lib/lua/?/init.lua Lua C module search paths: /usr/lib/prosody/?.so /usr/lib/lua/?.so /usr/lib/lua/loadall.so LuaRocks: Not installed # Lua module versions lfs: LuaFileSystem 1.6.2 lxp: LuaExpat 1.3.0 pposix: 0.3.6 socket: LuaSocket 3.0-rc1 ssl: 0.5.PR libevent is not enabled
Not using libevent rules out #583. This could be a certificate validation issue, does the clients say anything about that? Check their debug logs, if they have any. You could also try disabling HTTPS and see if the same thing happens, by setting https_ports = { }
Analysing client's log (Xabber for Android) in details, I see that the client starts a PUT operation with the correct URL (e.g. https://domain.tld/upload/<slot>/file.ext) but is returned a web page in which it's written "404 Not Found - Whatever you were looking for is not here, Where did you put it?" On the server, no files are actually created in the /upload area, just the folder with the given slot name. To test Prosody's http server efficiency, I manually created a small textfile in a known /upload subfolder, that I can regulary display on a browser using the right URL (e.g. https://domain.tld/upload/test/test.txt) It seems the problem arises in file creation, but I don't understand why the server can create the folder but not the file.
The directory is created when the slot is handed out, not when the file is uploaded, so this make sense. Are any options described in https://prosody.im/doc/http set? Is mod_http_upload loaded globally / on multiple VirtualHosts?
asterisk prosody # vi prosody.cfg.lua pidfile = "/var/run/prosody/prosody.pid" prosody_user = "prosody" prosody_group = "prosody" allow_registration = false authentication = "internal_plain" c2s_require_encryption = true c2s_ports = { 5222 } s2s_ports = { 5269 } groups_file = "/mnt/kd/prosody/sharedgroups.conf" admins = { "admin" } log = { info = "/var/log/prosody/prosody.log"; debug = "/var/log/prosody/prosody.dbg"; -- { levels = { min = "error" }, to = "syslog" }; error = "/var/log/prosody/prosody.err"; } -- Don't include ssl option "no_sslv3" since pre-Asterisk 1.8.31.1 and 11.13.1 u sed SSLv3 ssl = { options = { "no_sslv2", "no_ticket", "no_compression", "cipher_server_preferen ce", "single_dh_use", "single_ecdh_use" }; certificate = "/etc/prosody/certs/server.crt"; key = "/etc/prosody/certs/server.key"; } modules_enabled = { "posix", "roster", "saslauth", "tls", "disco", "private", "v card", "legacyauth", "version", "uptime", "time", "ping", "pep", "register", "ad hoc", "admin_adhoc", "admin_telnet", "log_auth", "dialback", "groups", "bosh", " http_upload" } modules_disabled = { "s2s" } console_ports = { 5582, 5583 } bosh_ports = { 5280 } http_ports = { 5280 } http_interfaces = { "*" } https_ports = { 5281 } https_interfaces = { "*" } http_files_dir = "/var/prosody" http_upload_path = "/var/prosody" http_external_url = "https://cdpa.noip.me/" http_upload_expire_after = { 604800 } http_upload_file_size_limit = { 10485760 } http_upload_quota = { 10485760 } http_max_content_size = { 1048576000 } network_default_read_size = "*a" VirtualHost "asterisk.private" VirtualHost "<domain.tld>"
(Please delete the domain shown in http_external_url I forgot clean)
If you have mod_http_upload loaded globally with many VirtualHosts that get the same URLs (either because same http_host or same http_external_url etc) then the requests may end up routed to a different instance than the one that issued the upload slot, and you get this behavior. Either alter the URLs so they are different for each host, or limit mod_http_upload to a single host, or make it a Component. I don't think we can do much about this behaviour, since it is a design issue, not a code issue. There are tweaks in place that are supposed to help, but they don't work.
ChangesWhat steps will reproduce the problem? 1. use the latest MOD_HTTP_UPLOAD.lua on Prosody 0.10 on debian 8. 2. use Gajim as client 3. check Prosody's "debug" output in logfile 4. error message given by Gajim will lead also to problem What is the expected output? The desired file should be uploaded to the server What do you see instead? File progress reaches 100% transferred, then "failed" message is shown debug log Mar 20 20:05:24 c2s86b6500 debug Handled 46 incoming stanzas Mar 20 20:05:24 c2s86b6500 debug Received[c2s]: <iq id='d5d8bbea-b1fd-4fa0-8410-dea2e7886e1f' type='get' to='upload.mydomain.com' from='test@mydomain.com/gajim.GJW8OJLV'> Mar 20 20:05:24 c2s86b6500 debug Given upload slot "6XX1QHT79KGYSwtV/PCN.pdf" Mar 20 20:05:24 c2s86b6500 debug #queue = 1 Mar 20 20:05:24 c2s86b6500 debug Queuing <r> (in a moment) Mar 20 20:05:24 c2s86b6500 debug Sending <r> (inside timer, before send) Mar 20 20:05:24 c2s86b6500 debug Sending <r> (inside timer, after send) Mar 20 20:05:24 c2s86b6500 debug Received[c2s]: <r xmlns='urn:xmpp:sm:3'> Mar 20 20:05:24 jabber.yorktondigital.ca:smacks debug Received ack request, acking for 46 On the server, no files are actually created in the /upload area, just the folder with the given slot name. Testing further especially looking into issue 583 mentioned in this issue, I can confirm the following: use_libevent = true using network_default_read_size ="*a" will not solve the issue, file is still not placed in /upload folder but the error message from Gajim has changed to: "Upload Error [ WinError 10060] a connection attempt failed because of the connection party did not properly respond after a periode of time or connecting host failed to respond" This new error message is due to using "network_default_read_size ="*a" DISABLING libevent DID solve the problem and uploads are working, files were placed into /upload folder, links were placed in message Also disabling network_default_read_size made no difference, http_upload working as described above. In my situation: prosody 0.10 from debian8 repository with last mod_http_upload AND disabling libevent in configuration solved http upload problem.