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

send_file HTTP::Server::ClientError #591

Open
itsezc opened this issue Oct 29, 2020 · 7 comments
Open

send_file HTTP::Server::ClientError #591

itsezc opened this issue Oct 29, 2020 · 7 comments
Labels
needs-more-info

Comments

@itsezc
Copy link

itsezc commented Oct 29, 2020

Description

Throws various errors related to HTTP::Server and IO:Error however the content loads and works.

Steps to Reproduce

require "kemal"

get "/" do | env |
	send_file env, "./public/jingles/1.mp3", "audio/mpeg"
end

Kemal.run

Expected behavior: No errors thrown, as the code is very basic and taken directly from the docs.

Actual behavior:

 main ● ?  ✔  crystal source/server.cr                                                                                               1.86 L  15:04:52
[development] Kemal is ready to lead at http://0.0.0.0:3000
Exception: Error while writing data to the client (HTTP::Server::ClientError)
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/response.cr:215:9 in 'unbuffered_write'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/io/buffered.cr:217:5 in 'flush'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/io/buffered.cr:156:7 in 'write'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/response.cr:86:7 in 'write'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/io.cr:1120:7 in 'copy'
  from lib/kemal/src/kemal/helpers/helpers.cr:169:7 in 'send_file'
  from source/server.cr:7:2 in '->'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/primitives.cr:255:3 in '->'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/primitives.cr:255:3 in 'process_request'
  from lib/kemal/src/kemal/route_handler.cr:17:7 in 'call'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/websocket_handler.cr:13:14 in 'call'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/exception_handler.cr:8:7 in 'call'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/log_handler.cr:8:37 in 'call'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/init_handler.cr:12:7 in 'call'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/request_processor.cr:50:11 in 'process'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server.cr:513:5 in 'handle_client'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server.cr:468:13 in '->'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/primitives.cr:255:3 in 'run'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/fiber.cr:92:34 in '->'
Caused by: Error writing to socket: Broken pipe (IO::Error)
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/io/evented.cr:82:13 in 'unbuffered_write'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/io/buffered.cr:152:14 in 'write'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/response.cr:211:11 in 'unbuffered_write'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/io/buffered.cr:217:5 in 'flush'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/io/buffered.cr:156:7 in 'write'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/response.cr:86:7 in 'write'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/io.cr:1120:7 in 'copy'
  from lib/kemal/src/kemal/helpers/helpers.cr:169:7 in 'send_file'
  from source/server.cr:7:2 in '->'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/primitives.cr:255:3 in '->'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/primitives.cr:255:3 in 'process_request'
  from lib/kemal/src/kemal/route_handler.cr:17:7 in 'call'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/websocket_handler.cr:13:14 in 'call'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/exception_handler.cr:8:7 in 'call'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/log_handler.cr:8:37 in 'call'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/init_handler.cr:12:7 in 'call'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/request_processor.cr:50:11 in 'process'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server.cr:513:5 in 'handle_client'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server.cr:468:13 in '->'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/primitives.cr:255:3 in 'run'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/fiber.cr:92:34 in '->'

2020-10-29T09:34:58.980583Z  ERROR - http.server: Unhandled exception on HTTP::Handler
Closed stream (IO::Error)
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/io.cr:118:5 in 'check_open'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/io/buffered.cr:131:15 in 'write'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/response.cr:86:7 in 'write'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/io.cr:470:7 in 'write_utf8'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/string.cr:4789:5 in 'to_s'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/io.cr:174:5 in '<<'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/io.cr:188:5 in 'print'
  from lib/kemal/src/kemal/helpers/templates.cr:33:3 in 'render_500'
  from lib/kemal/src/kemal/exception_handler.cr:17:7 in 'call'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/log_handler.cr:8:37 in 'call'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/init_handler.cr:12:7 in 'call'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server/request_processor.cr:50:11 in 'process'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server.cr:513:5 in 'handle_client'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/http/server.cr:468:13 in '->'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/primitives.cr:255:3 in 'run'
  from ../../../../../usr/local/Cellar/crystal/0.35.1_1/src/fiber.cr:92:34 in '->'

Reproduces how often: Everytime

Versions

LLVM: 10.0.0
Default target: x86_64-apple-macosx

OS: Mac OS Catalina
@Dan-Do
Copy link

Dan-Do commented Jan 7, 2021

I have the same issue. How to reproduce (don't know if it works on your environment):

setup local server (build using kemal), then start the process on terminal
open Firefox then go to the home url of your site, for example mine is http://0.0.0.0:8080/
click any link to go to other page, for example http://0.0.0.0:8080/page1
open terminal, press CTLR+C to shutdown your server process
start a new server instance
go to the browser, click the back button to go 1 level of history (ex http://0.0.0.0:8080/)
check to kemal error log

Exception: Error while writing data to the client (HTTP::Server::ClientError)
  from ../../../../../usr/share/crystal/src/http/server/response.cr:216:9 in 'unbuffered_write'
  from ../../../../../usr/share/crystal/src/io/buffered.cr:152:14 in 'write'
  from ../../../../../usr/share/crystal/src/http/server/response.cr:86:7 in 'write'
  from ../../../../../usr/share/crystal/src/io.cr:470:7 in 'write_utf8'
  from ../../../../../usr/share/crystal/src/string.cr:4961:5 in 'to_s'
  from ../../../../../usr/share/crystal/src/io.cr:174:5 in '<<'
  from ../../../../../usr/share/crystal/src/io.cr:188:5 in 'print'
  from lib/kemal/src/kemal/route_handler.cr:55:7 in 'process_request'
  from lib/kemal/src/kemal/route_handler.cr:17:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/websocket_handler.cr:13:14 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/filter_handler.cr:21:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/exception_handler.cr:8:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from ../../../../../usr/share/crystal/src/http/server/handlers/static_file_handler.cr:103:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/null_log_handler.cr:5:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/init_handler.cr:12:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/request_processor.cr:50:11 in 'process'
  from ../../../../../usr/share/crystal/src/http/server.cr:513:5 in 'handle_client'
  from ../../../../../usr/share/crystal/src/http/server.cr:468:13 in '->'
  from ../../../../../usr/share/crystal/src/primitives.cr:255:3 in 'run'
  from ../../../../../usr/share/crystal/src/fiber.cr:92:34 in '->'
  from ???
Caused by: Error writing to socket: Broken pipe (IO::Error)
  from ../../../../../usr/share/crystal/src/io/evented.cr:82:13 in 'unbuffered_write'
  from ../../../../../usr/share/crystal/src/io/buffered.cr:152:14 in 'write'
  from ../../../../../usr/share/crystal/src/http/server/response.cr:209:11 in 'unbuffered_write'
  from ../../../../../usr/share/crystal/src/io/buffered.cr:152:14 in 'write'
  from ../../../../../usr/share/crystal/src/http/server/response.cr:86:7 in 'write'
  from ../../../../../usr/share/crystal/src/io.cr:470:7 in 'write_utf8'
  from ../../../../../usr/share/crystal/src/string.cr:4961:5 in 'to_s'
  from ../../../../../usr/share/crystal/src/io.cr:174:5 in '<<'
  from ../../../../../usr/share/crystal/src/io.cr:188:5 in 'print'
  from lib/kemal/src/kemal/route_handler.cr:55:7 in 'process_request'
  from lib/kemal/src/kemal/route_handler.cr:17:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/websocket_handler.cr:13:14 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/filter_handler.cr:21:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/exception_handler.cr:8:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from ../../../../../usr/share/crystal/src/http/server/handlers/static_file_handler.cr:103:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/null_log_handler.cr:5:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/init_handler.cr:12:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/request_processor.cr:50:11 in 'process'
  from ../../../../../usr/share/crystal/src/http/server.cr:513:5 in 'handle_client'
  from ../../../../../usr/share/crystal/src/http/server.cr:468:13 in '->'
  from ../../../../../usr/share/crystal/src/primitives.cr:255:3 in 'run'
  from ../../../../../usr/share/crystal/src/fiber.cr:92:34 in '->'
  from ???

There are some reports on this link crystal-lang/crystal#9065

@khan-vinn
Copy link

I have the same issue. How to reproduce (don't know if it works on your environment):

setup local server (build using kemal), then start the process on terminal
open Firefox then go to the home url of your site, for example mine is http://0.0.0.0:8080/
click any link to go to other page, for example http://0.0.0.0:8080/page1
open terminal, press CTLR+C to shutdown your server process
start a new server instance
go to the browser, click the back button to go 1 level of history (ex http://0.0.0.0:8080/)
check to kemal error log

Exception: Error while writing data to the client (HTTP::Server::ClientError)
  from ../../../../../usr/share/crystal/src/http/server/response.cr:216:9 in 'unbuffered_write'
  from ../../../../../usr/share/crystal/src/io/buffered.cr:152:14 in 'write'
  from ../../../../../usr/share/crystal/src/http/server/response.cr:86:7 in 'write'
  from ../../../../../usr/share/crystal/src/io.cr:470:7 in 'write_utf8'
  from ../../../../../usr/share/crystal/src/string.cr:4961:5 in 'to_s'
  from ../../../../../usr/share/crystal/src/io.cr:174:5 in '<<'
  from ../../../../../usr/share/crystal/src/io.cr:188:5 in 'print'
  from lib/kemal/src/kemal/route_handler.cr:55:7 in 'process_request'
  from lib/kemal/src/kemal/route_handler.cr:17:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/websocket_handler.cr:13:14 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/filter_handler.cr:21:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/exception_handler.cr:8:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from ../../../../../usr/share/crystal/src/http/server/handlers/static_file_handler.cr:103:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/null_log_handler.cr:5:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/init_handler.cr:12:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/request_processor.cr:50:11 in 'process'
  from ../../../../../usr/share/crystal/src/http/server.cr:513:5 in 'handle_client'
  from ../../../../../usr/share/crystal/src/http/server.cr:468:13 in '->'
  from ../../../../../usr/share/crystal/src/primitives.cr:255:3 in 'run'
  from ../../../../../usr/share/crystal/src/fiber.cr:92:34 in '->'
  from ???
Caused by: Error writing to socket: Broken pipe (IO::Error)
  from ../../../../../usr/share/crystal/src/io/evented.cr:82:13 in 'unbuffered_write'
  from ../../../../../usr/share/crystal/src/io/buffered.cr:152:14 in 'write'
  from ../../../../../usr/share/crystal/src/http/server/response.cr:209:11 in 'unbuffered_write'
  from ../../../../../usr/share/crystal/src/io/buffered.cr:152:14 in 'write'
  from ../../../../../usr/share/crystal/src/http/server/response.cr:86:7 in 'write'
  from ../../../../../usr/share/crystal/src/io.cr:470:7 in 'write_utf8'
  from ../../../../../usr/share/crystal/src/string.cr:4961:5 in 'to_s'
  from ../../../../../usr/share/crystal/src/io.cr:174:5 in '<<'
  from ../../../../../usr/share/crystal/src/io.cr:188:5 in 'print'
  from lib/kemal/src/kemal/route_handler.cr:55:7 in 'process_request'
  from lib/kemal/src/kemal/route_handler.cr:17:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/websocket_handler.cr:13:14 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/filter_handler.cr:21:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/exception_handler.cr:8:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from ../../../../../usr/share/crystal/src/http/server/handlers/static_file_handler.cr:103:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/null_log_handler.cr:5:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/handler.cr:28:7 in 'call_next'
  from lib/kemal/src/kemal/init_handler.cr:12:7 in 'call'
  from ../../../../../usr/share/crystal/src/http/server/request_processor.cr:50:11 in 'process'
  from ../../../../../usr/share/crystal/src/http/server.cr:513:5 in 'handle_client'
  from ../../../../../usr/share/crystal/src/http/server.cr:468:13 in '->'
  from ../../../../../usr/share/crystal/src/primitives.cr:255:3 in 'run'
  from ../../../../../usr/share/crystal/src/fiber.cr:92:34 in '->'
  from ???

There are some reports on this link crystal-lang/crystal#9065

may be file's path incorrect

should be ->
/path/to/your/file/from/parent/directory/

@Sija
Copy link
Contributor

Sija commented May 24, 2024 •
edited
Loading

The Error writing to socket: Broken pipe (IO::Error) error most likely occurs when the client disconnects before the server fulfils the request. IIRC in most cases is rather harmless and can be ignored.

See crystal-lang/crystal#9034 (comment) and crystal-lang/crystal#9115 (comment).

@Sija
Copy link
Contributor

Sija commented May 24, 2024

I think this issue can safely be closed.

@unixfox
Copy link

unixfox commented May 28, 2024 •
edited
Loading

It's an issue for high traffic applications, you are flooded by these logs, and you can't read the other useful lines of log.

In invidious, we had to override the class in order to not get these exceptions: https://github.com/iv-org/invidious/blob/master/src/invidious/helpers/crystal_class_overrides.cr#L51

Otherwise, on a high traffic application we would get these errors every second: iv-org/invidious#1416

For me, it is still worth it to keep this issue open until we find a configurable parameter to mute these errors. Kemal is the only library where I have seen these error logs, I have never seen such logs in other libraries in other programming language.

@sdogruyol
Copy link
Member

Hey @unixfox thanks a lot for the feedback, I'll reopen the issue. @straight-shoota do you have any idea if we can do anything about this in std-lib or kemal itself?

@sdogruyol sdogruyol reopened this Jun 3, 2024
@sdogruyol sdogruyol mentioned this issue Jun 3, 2024
Open
@curioustolearn
Copy link

I think I ran into this issue today when about 60 people tried to access my server at the same time. Here is the error I saw (multiple times) and the server became unresponsive. I just wanted to share this here. Is there a solution to this? It seems like it is not only a problem with logs getting cluttered with these messages, it also affects the responsiveness of the server.

Thank you.

Sep 03 14:26:02 webapps-server crystalquiz[62307]: Unhandled exception in spawn: Error while flushing data to the client (HTTP::Server::ClientError)
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from /usr/share/crystal/src/http/server/response.cr:328:9 in 'unbuffered_flush'
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from /usr/share/crystal/src/io/buffered.cr:251:5 in 'flush'
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from /usr/share/crystal/src/io/buffered.cr:258:5 in 'close'
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from /usr/share/crystal/src/http/server/response.cr:298:9 in 'close'
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from /usr/share/crystal/src/http/server/request_processor.cr:63:11 in 'process'
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from /usr/share/crystal/src/http/server.cr:521:5 in 'handle_client'
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from /usr/share/crystal/src/http/server.cr:451:5 in '->'
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from /usr/share/crystal/src/fiber.cr:143:11 in 'run'
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from /usr/share/crystal/src/fiber.cr:95:34 in '->'
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from ???
Sep 03 14:26:02 webapps-server crystalquiz[62307]: Caused by: Error writing to socket (#<TCPSocket:0x76ed8e064690>): Broken pipe (IO::Error)
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from /usr/share/crystal/src/io/evented.cr:45:11 in 'write'
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from /usr/share/crystal/src/crystal/system/socket.cr:89:5 in 'system_write'
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from /usr/share/crystal/src/socket.cr:442:16 in 'unbuffered_write'
Sep 03 14:26:02 webapps-server crystalquiz[62307]:   from /usr/share/crystal/src/io/buffered.cr:250:5 in 'flush'

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
needs-more-info
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
7 participants
@Sija @sdogruyol @curioustolearn @unixfox @itsezc @Dan-Do @khan-vinn