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.

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

[Meta] Invidious crashes often for no reason #1439

Closed
TheFrenchGhosty opened this issue Oct 24, 2020 · 6 comments
Closed

[Meta] Invidious crashes often for no reason #1439

TheFrenchGhosty opened this issue Oct 24, 2020 · 6 comments
Labels
bug Something isn't working stale type:server-side

Comments

@TheFrenchGhosty
Copy link
Member

This has already been reported multiples time, but from what I know, no issues were opened on Github about it.

Like #1345 and #1438 this is an issue to regroup as much information about this problem.

In this issue we will also keep track of the progress in fixing it.


On an instance running for example those cronjobs to check and restart a broken Invidious...

* * * * * curl -o /dev/null -s -m 10 http://localhost:3000 || systemctl restart invidious
* * * * * sleep 30 && curl -o /dev/null -s -m 10 http://localhost:3000 || systemctl restart invidious

... Invidious will crash for no reason multiple times a day.

According to the syslog the restart check cronjob caught a crash and restarted Invidious

$ grep "invidious.service: Main process exited" /var/log/syslog | wc -l
116
$ grep "invidious.service: Main process exited" /var/log/syslog.1 | wc -l
126
$zgrep "invidious.service: Main process exited" /var/log/syslog.2.gz | wc -l
209
$ zgrep "invidious.service: Main process exited" /var/log/syslog.3.gz | wc -l
201
$ zgrep "invidious.service: Main process exited" /var/log/syslog.4.gz | wc -l
180

The frequency of the crashes depend on the number of users of an instance. The crashes from above are from a public instance used by thousands of users.

@ytprivatecom
Copy link

ytprivatecom commented Jan 20, 2021

Stacktrace from a crash, high memory usage before the stack trace as well.

Jan 20 15:02:45 localhost invidious[3130]: Invalid memory access (signal 11) at address 0x0
Jan 20 15:02:45 localhost invidious[3130]: [0x55bef976f986] ???
Jan 20 15:02:45 localhost invidious[3130]: [0x55bef93c2d0d] __crystal_sigfault_handler +525
Jan 20 15:02:45 localhost invidious[3130]: [0x7f948c65c730] ???
Jan 20 15:02:45 localhost invidious[3130]: [0x55bef98106bd] lsquic_hash_first +13
Jan 20 15:02:45 localhost invidious[3130]: [0x55bef97de34c] ???
Jan 20 15:02:45 localhost invidious[3130]: [0x55bef948bf92] ???
Jan 20 15:02:45 localhost invidious[3130]: [0x55bef93b92cc] ???
Jan 20 15:02:45 localhost invidious[3130]: [0x0] ???
Jan 20 15:02:45 localhost systemd[1]: invidious.service: Main process exited, code=exited, status=11/n/a

wsRBQQEl2h

@FireMasterK
Copy link
Contributor

My instance crashes every few minutes because of this as well. All of the crashes are signal 11 crashes.

@TheFrenchGhosty TheFrenchGhosty changed the title Invidious crashes often for no reason [Meta] Invidious crashes often for no reason Feb 25, 2021
@Perflyst
Copy link
Contributor

Perflyst commented Apr 8, 2021

Some more traces

Apr  8 12:21:40 invidious invidious[24637]: Invalid memory access (signal 11) at address 0x0
Apr  8 12:21:40 invidious invidious[24637]: [0x56272f2d88a6] print_backtrace at /usr/share/crystal/src/exception/call_stack.cr:129:5
Apr  8 12:21:40 invidious invidious[24637]: [0x56272ef9f7ac] __crystal_sigfault_handler at /usr/share/crystal/src/signal.cr:347:3
Apr  8 12:21:40 invidious invidious[24637]: [0x7f15aa6bb730] ???
Apr  8 12:21:40 invidious invidious[24637]: [0x56272fb7507f] lsquic_attq_pop +42
Apr  8 12:21:40 invidious invidious[24637]: [0x56272fa569de] lsquic_engine_process_conns +227
Apr  8 12:21:40 invidious invidious[24637]: [0x56272f0067ab] -> at /home/invidious/invidious/lib/lsquic/src/lsquic/client.cr:226:11
Apr  8 12:21:40 invidious invidious[24637]: [0x56272f3b1f59] run at /usr/share/crystal/src/primitives.cr:255:3
Apr  8 12:21:40 invidious invidious[24637]: [0x56272ef9ecb6] -> at /usr/share/crystal/src/fiber.cr:92:34
Apr  8 12:21:40 invidious invidious[24637]: [0x0] ???
Apr  8 00:20:16 invidious invidious[9947]: Invalid memory access (signal 11) at address 0x20
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c090e76] print_backtrace at /usr/share/crystal/src/exception/call_stack.cr:129:5
Apr  8 00:20:16 invidious invidious[9947]: [0x55663bd5765c] __crystal_sigfault_handler at /usr/share/crystal/src/signal.cr:347:3
Apr  8 00:20:16 invidious invidious[9947]: [0x7fc387c5e730] ???
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c9c187b] GC_finish_collection +539
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c9c1310] GC_try_to_collect_inner +336
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c9c2674] GC_collect_or_expand +196
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c9c655b] GC_alloc_large +235
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c9c6c53] GC_generic_malloc +307
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c9c6dd1] GC_malloc_kind_global +225
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c10dd96] malloc at /usr/share/crystal/src/gc/boehm.cr:110:5
Apr  8 00:20:16 invidious invidious[9947]: [0x55663bd429ae] __crystal_malloc64 at /usr/share/crystal/src/gc.cr:24:3
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c218993] malloc at /usr/share/crystal/src/primitives.cr:153:3
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2188f4] initialize at /usr/share/crystal/src/deque.cr:51:17
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c21883d] new at /usr/share/crystal/src/deque.cr:41:3
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2176ce] initialize at /usr/share/crystal/src/channel.cr:178:16
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c21764f] new:capacity at /usr/share/crystal/src/channel.cr:171:3
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c214a73] new at /home/invidious/invidious/lib/lsquic/src/lsquic/channeled_pipe.cr:82:5
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2149d5] new at /home/invidious/invidious/lib/lsquic/src/lsquic/channeled_pipe.cr:76:3
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c39a5b5] send_request at /home/invidious/invidious/lib/lsquic/src/lsquic/client.cr:499:24
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c39a4cd] exec_internal_single at /home/invidious/invidious/lib/lsquic/src/lsquic/client.cr:455:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c39a47b] exec_internal at /home/invidious/invidious/lib/lsquic/src/lsquic/client.cr:448:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c39a456] exec at /home/invidious/invidious/lib/lsquic/src/lsquic/client.cr:444:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c39a436] exec at /home/invidious/invidious/lib/lsquic/src/lsquic/client.cr:525:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c39a417] get at /home/invidious/invidious/lib/lsquic/src/lsquic/client.cr:381:5
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c00089b] search at /home/invidious/invidious/src/invidious/search.cr:267:35
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c00007d] -> at /home/invidious/invidious/src/invidious.cr:2569:27
Apr  8 00:20:16 invidious invidious[9947]: [0x55663bddd666] -> at /usr/share/crystal/src/primitives.cr:255:3
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2a6d0d] process_request at /usr/share/crystal/src/primitives.cr:255:3
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2a6c56] call at /home/invidious/invidious/lib/kemal/src/kemal/route_handler.cr:17:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2ad69e] call_next at /usr/share/crystal/src/http/server/handler.cr:28:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2acebb] call at /home/invidious/invidious/lib/kemal/src/kemal/websocket_handler.cr:13:14
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c29d763] call_next at /usr/share/crystal/src/http/server/handler.cr:28:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c29d089] call at /home/invidious/invidious/lib/kemal/src/kemal/filter_handler.cr:21:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2e131d] call_next at /usr/share/crystal/src/http/server/handler.cr:28:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2e0e59] call at /home/invidious/invidious/src/invidious/helpers/handlers.cr:212:5
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2df3f6] call_next at /usr/share/crystal/src/http/server/handler.cr:28:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2dd376] call at /home/invidious/invidious/src/invidious/helpers/handlers.cr:94:12
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2e0aa8] call_next at /usr/share/crystal/src/http/server/handler.cr:28:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2df8d5] call at /home/invidious/invidious/src/invidious/helpers/handlers.cr:158:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2dceaf] call_next at /usr/share/crystal/src/http/server/handler.cr:28:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2dc8f2] call at /home/invidious/invidious/src/invidious/helpers/handlers.cr:70:5
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c77efd1] call_next at /usr/share/crystal/src/http/server/handler.cr:28:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c77cc50] call at /home/invidious/invidious/src/invidious/helpers/static_file_handler.cr:189:11
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2dbc49] call_next at /usr/share/crystal/src/http/server/handler.cr:28:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2db7a0] call at /home/invidious/invidious/lib/kemal/src/kemal/exception_handler.cr:8:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c3b6ad4] call_next at /usr/share/crystal/src/http/server/handler.cr:28:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c3b6622] call at /home/invidious/invidious/src/invidious/helpers/logger.cr:17:35
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2a4fe1] call_next at /usr/share/crystal/src/http/server/handler.cr:28:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c2a4ce7] call at /home/invidious/invidious/lib/kemal/src/kemal/init_handler.cr:12:7
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c790467] process at /usr/share/crystal/src/http/server/request_processor.cr:50:11
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c78e814] handle_client at /usr/share/crystal/src/http/server.cr:513:5
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c07b9c8] -> at /usr/share/crystal/src/http/server.cr:468:13
Apr  8 00:20:16 invidious invidious[9947]: [0x55663c16a239] run at /usr/share/crystal/src/primitives.cr:255:3
Apr  8 00:20:16 invidious invidious[9947]: [0x55663bd56b66] -> at /usr/share/crystal/src/fiber.cr:92:34
Apr  8 00:20:16 invidious invidious[9947]: [0x0] ???
Apr  8 00:21:01 invidious invidious[9952]: Invalid memory access (signal 11) at address 0xa0
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cd685e76] print_backtrace at /usr/share/crystal/src/exception/call_stack.cr:129:5
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cd34c65c] __crystal_sigfault_handler at /usr/share/crystal/src/signal.cr:347:3
Apr  8 00:21:01 invidious invidious[9952]: [0x7f6061ae2730] ???
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cd8083d1] check_open at /usr/share/crystal/src/io.cr:118:5
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cd8084d5] write at /usr/share/crystal/src/io/buffered.cr:131:15
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cd992f4f] stream_readf at /home/invidious/invidious/lib/lsquic/src/lsquic/client.cr:18:7
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cd3b32d6] ~procProc(Pointer(Void), Pointer(UInt8), UInt64, Int32, UInt64) +6
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cde84666] ???
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cde84a96] ???
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cde84c76] lsquic_stream_readf +258
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cd992e67] on_read at /home/invidious/invidious/lib/lsquic/src/lsquic/client.cr:87:7
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cd3b32c6] ~procProc(LibLsquic::StreamT, Pointer(Void), Pointer(Void)) +6
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cde85f34] ???
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cde86973] lsquic_stream_dispatch_read_events +97
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cde14f75] ???
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cde15e09] ???
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cde07ebd] ???
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cde054c4] lsquic_engine_process_conns +265
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cd3b358b] -> at /home/invidious/invidious/lib/lsquic/src/lsquic/client.cr:226:11
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cd75f239] run at /usr/share/crystal/src/primitives.cr:255:3
Apr  8 00:21:01 invidious invidious[9952]: [0x5589cd34bb66] -> at /usr/share/crystal/src/fiber.cr:92:34
Apr  8 00:21:01 invidious invidious[9952]: [0x0] ???

@FireMasterK
Copy link
Contributor

Maybe helpful: changing from the legacy gquic to the IETF drafts - iv-org/lsquic.cr#16

@syeopite
Copy link
Member

syeopite commented May 18, 2021

Turning on the debugging in lsquic.cr reveals that the error (or at least one of them) is caused by this assertion failing !(conn->cn_flags & flag) in the lsquic lib. According to litespeedtech/lsquic#120 and the traces above that seems to be caused by multi threading access issues.

jakubgs added a commit to jakubgs/nixos-config that referenced this issue Mar 4, 2022
This is a known issue:
iv-org/invidious#1439
NixOS/nixpkgs#136993 (comment)

Signed-off-by: Jakub Sokołowski <jakub@status.im>
@github-actions
Copy link

This issue has been automatically marked as stale and will be closed in 30 days because it has not had recent activity and is much likely outdated. If you think this issue is still relevant and applicable, you just have to post a comment and it will be unmarked.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working stale type:server-side
Projects
Status: Done
Development

No branches or pull requests

5 participants