How to break std::cout
-
Vielleicht etwas click baity der Titel, aber dies ist die Story wie
std::cout
bei mir ab und zu den Dienst quittiert hat.
Ab und zu? Genau, es handelte sich hier nicht um einen deterministischen Ausfall meiner Logging-Ausgaben, sondern nur ein sporadischer, der dann aber dazu führte, dasscout
für den Rest des Programms nichts mehr aus gab.
Was genau ist passiert? Also ich habe, wie so viele andere Leute auch,cout
(cerr
undclog
verhalten sich genauso!) verwendet um Geschehnisse im Terminal zu loggen. Nun verwende ichstd::thread
undboost::asio
um asynchron Operationen auszuführen, und die event handler wurden auch korrekt aufgerufen und ausgeführt. Nur manchmal passierte es, dass irgendwann nichts mehr ins Log geschrieben wurde! Alle folgenden Logging-Aufrufe taten einfach nichts mehr! Was war da los? Zeit für einstd::cout.exceptions(std::ios_base::failbit | std::ios_base::badbit);
Und siehe da, manchmal wird dann eine Exception geworfen bei einer Logging-Ausgabe! Es stellt sich heraus, dass manchmal das
badbit
gesetzt wird. Dabei mache nich nichts spektakuläres: nur Text ausgeben… Was war da los?
Wenn ichstd::cout
durchstd::printf
ersetzt habe, funktionierte es scheinbar immer. Scheinbar. Es fehlten ab und zu mal einige Ausgaben! Natürlich nur seeeehr selten, was mich einige Zeit gekostet hat es heraus zu finden. Aber spätere Ausgaben haben trotzdem funktioniert und nicht wie beicout
, wo dann alles aufgehört hat zu funktionieren (liegt ambadbit
…). Irgendwann kam ich mal auf die gloreiche Idee den Rückgabewert vonprintf
zu testen. Siehe da, es schlägt manchmal fehl! Leute, prüft eure Rückgabewerte, auch bei Logging-Ausgaben!
Okay,printf
schlägt fehl (puts
,fwrite
, usw. übrigens auch…), aber warum? Und warum nur sehr selten? Aber das erklärt zumindest, warumcout
dann aufgehört hat zu funktionieren, denn es verwendet intern standardmäßig die C IO Funktionen und wenn die fehlschlagen, wird dasbadbit
gesetzt.
Zeit noch eine Stufe tiefer zu gehen und den nakten Syscallwrite
aufzurufen (ich bin unter Linux unterwegs). Selbes Verhalten wie bei der C IO. Manchmal schlägt der fehl. Hier kann ich nunerrno
prüfen (darf man das bei den C Funktionen schon?) um heraus zu finden was für ein Fehler vorliegt! Der Übeltäter istEINTR
. Das bedeutet, dass manchmal ein Signal an meinen Prozess geschickt wird undwrite
unterbrochen wird. Wo kommt das Signal her? Keine Ahnung, vermutlich irgendwo in der internen Funktionsweise vonstd::thread
und/oderboost::asio
… Denn ohne die ist mir sowas noch nie passiert, und im Internet habe ich auch absolut nichts dazu gefunden.Hier ein Testprogramm in C:
#include <stdio.h> #include <signal.h> static void signal_handler(int sig) { (void)sig; } int main(void) { struct sigaction sa = { .sa_handler = &signal_handler, }; sigemptyset(&sa.sa_mask); if (sigaction(SIGINT, &sa, 0) == -1) { return 1; } while (1) { if (puts("line") == EOF) { return 2; } } }
Beendet sich nach Ctrl+C mit exit code 2, obwohl ich intuitiv vermutet hätte, dass die C IO Funktionen so schlau sind es nochmal zu probieren. Scheinbar nicht.
Bin ich der einzige, der dieses Verhalten unintuitiv findet?
-
Der Versuch das Mini Beispiel zu übersetzen ergibt bei mir
gcc -O2 -std=c17 -Wpedantic -Wall -Wextra signal_handler.c -o signal_handler signal.c: In function ‘main’: signal.c:9:9: error: variable ‘sa’ has initializer but incomplete type 9 | struct sigaction sa = { | ^~~~~~~~~ signal.c:10:4: error: ‘struct sigaction’ has no member named ‘sa_handler’ 10 | .sa_handler = &signal_handler, | ^~~~~~~~~~ signal.c:10:17: warning: excess elements in struct initializer 10 | .sa_handler = &signal_handler, | ^ signal.c:10:17: note: (near initialization for ‘sa’) signal.c:9:19: error: storage size of ‘sa’ isn’t known 9 | struct sigaction sa = { | ^~ signal.c:12:2: warning: implicit declaration of function ‘sigemptyset’ [-Wimplicit-function-declaration] 12 | sigemptyset(&sa.sa_mask); | ^~~~~~~~~~~ signal.c:13:6: warning: implicit declaration of function ‘sigaction’ [-Wimplicit-function-declaration] 13 | if (sigaction(SIGINT, &sa, 0) == -1) { | ^~~~~~~~~ signal.c:9:19: warning: unused variable ‘sa’ [-Wunused-variable] 9 | struct sigaction sa = { | ^~
Da ist einiges nicht korrekt, auch nicht für ein Minimalbeispiel.
-
Dann fehlt entweder vor den Includes ein
#define _POSIX_C_SOURCE 200809L
oder mit
-D_POSIX_C_SOURCE=200809L
kompilieren.
-
@Biolunar sagte in How to break std::cout:
dass die C IO Funktionen so schlau sind es nochmal zu probieren. Scheinbar nicht.
Kommt darauf an, ob sa_flags SA_RESTART enthält.
-
@manni66 klar kann man das angeben. Dann müsste ich das aber bei jedem der Signale von 1 bis SIGRTMAX setzen, um dieses Verhalten auch wirklich für jedes Signal zu haben (hab ja keine Ahnung welches kommen könnte). Und SA_RESTART gilt nur für die Syscalls und nicht für die stdio Funktionen.
-
Warum nutzt Du nicht
(*sa_sigaction)(int, siginfo_t *, void *);
aus dem sigaction struct, so dass Du mehr Informationen bekommst, was da passiert?
-
@john-0 Was soll mir das bringen? Das müsste ja auch für jedes erdenkliche Signal gesetzt werden.
-
@Biolunar sagte in How to break std::cout:
@john-0 Was soll mir das bringen? Das müsste ja auch für jedes erdenkliche Signal gesetzt werden.
Das wird nur für das gesetzte signal verwendet. Das geht dann ungefähr so (printf wird in einem echtem Handler nicht wirklich funktionieren).
#define _POSIX_C_SOURCE 200809L #include <stdio.h> #include <stdlib.h> #include <signal.h> #include <errno.h> #include <string.h> void sigaction_handler (int signal, siginfo_t* si, void* p) { static int v = 0; printf("\nsignal: %i\n", signal); printf("si_signo: %i\n",si->si_signo); printf("si_errno: %i\n",si->si_errno); printf("si_code: %i\n",si->si_code); v = si->si_pid; printf("si_pid: %i\n",v); v = si->si_uid; printf("si_uid: %i\n",v); printf("si_status: %i\n",si->si_status); printf("usw.\n"); printf("ucontext address:%p\n",p); } int main(void) { int rc = EXIT_SUCCESS; const size_t str_length = 1024; char* str = malloc(str_length); struct sigaction sa = { .sa_sigaction = &sigaction_handler, }; sigemptyset(&sa.sa_mask); sigaddset(&sa.sa_mask, SA_SIGINFO); if (-1 == sigaction(SIGINT, &sa, NULL)) { int errnov = errno; strerror_r(errnov, str, str_length); printf("%s\n",str); rc = EXIT_FAILURE; } else { for (;;) { /* if (EOF == puts("line")) { rc = 2; break; } */ } } free(str); return rc; }
-
@john-0 Ich sehe immer noch nicht was ich dadurch gewinnen soll. Ich habe zwar mehr Infos, aber das hilft mir doch nicht die C und C++ stdlib stabiler zu machen.
Um die C++ Standard Streams zu reparieren habe ich mir meinen eigenen
streambuf
geschrieben:#include <cerrno> #include <cstddef> #include <streambuf> #include <system_error> #include <unistd.h> class StreamBuf : public std::streambuf { char_type* _buffer = nullptr; std::streamsize _size = 0; void writeAll(int fd, void const* data, std::size_t count) { std::size_t written = 0; while (written < count) { ssize_t ret = ::write(fd, static_cast<unsigned char const*>(data) + written, count - written); if (ret < 0) { if (errno == EINTR) { continue; } throw std::system_error{errno, std::system_category(), "write"}; } written += static_cast<std::size_t>(ret); } } protected: std::streambuf* setbuf(char_type* s, std::streamsize n) override { _buffer = s; _size = n; setp(_buffer, _buffer + _size); return this; } int sync() override try { auto diff = pptr() - pbase(); if (diff < 0) { return -1; } else if (diff > 0) { writeAll(1, pbase(), static_cast<std::size_t>(diff)); setp(pbase(), epptr()); } return 0; } catch (...) { return -1; } int_type overflow(int_type ch = traits_type::eof()) override try { if (sync() == -1) { return traits_type::eof(); } if (!traits_type::eq_int_type(ch, traits_type::eof())) { char c = traits_type::to_char_type(ch); auto diff = epptr() - pptr(); if (diff > 0) { *pptr() = c; pbump(1); } else { writeAll(1, &c, 1); } } return traits_type::not_eof(ch); } catch (...) { return traits_type::eof(); } };
-
@Biolunar sagte in How to break std::cout:
@john-0 Ich sehe immer noch nicht was ich dadurch gewinnen soll. Ich habe zwar mehr Infos, aber das hilft mir doch nicht die C und C++ stdlib stabiler zu machen.
Ein SIGINT wird Dir nicht ohne Grund zugeschickt! Anstatt nun anzufangen irgend welchen Workarounds zu basteln, solltest Du zuerst abklären weshalb das passiert. Denn üblicherweise gibt es dafür einen sinnvollen Grund.
-
@john-0 ähhh ja. SIGINT hab ich in dem Beispiel nur zu Testzwecken genommen, weil das einfach über die Tastatur erzeugt werden kann.
std::thread
oderboost::asio
verwenden ein anderes Signal zur Inter-Thread-Kommunikation. Ich könnte nun herausfinden welche Signale dort Verwendung finden, und dann? Ich könnte bei diesen dann manuellSA_RESTART
als flag setzen, aber das wäre ein Hack von mir. Portabel ist was anderes, denn da würde ich mich auf ein Implementierungsdetail einer Bibliothek verlassen.
-
@Biolunar sagte in How to break std::cout:
@john-0 ähhh ja. SIGINT hab ich in dem Beispiel nur zu Testzwecken genommen, weil das einfach über die Tastatur erzeugt werden kann.
std::thread
oderboost::asio
verwenden ein anderes Signal zur Inter-Thread-Kommunikation. Ich könnte nun herausfinden welche Signale dort Verwendung finden, und dann?Es geht darum die Ursache dafür zu finden, denn irgend was machst Du, was bei IO Probleme verursacht. Du fängst an im Nebel herumzustochern ohne zu wissen was falsch läuft.
-
@Biolunar sagte in How to break std::cout:
std::thread oder boost::asio verwenden ein anderes Signal zur Inter-Thread-Kommunikation
Nein
-
std::thread
kann ich in der Tat ausschließen. Das lag aber nahe, denn pthread verwendet intern mindestens ein realtime signal.
Vielleicht liegts anboost::process
, denn folgendes Beispiel stürzt recht schnell ab (aber nicht deterministisch):#include <cstdlib> #include <cstddef> #include <string> #include <iostream> #include <exception> #include <boost/asio.hpp> #include <boost/process.hpp> static boost::asio::io_context ioc; static boost::asio::streambuf stdoutBuf; static boost::process::async_pipe aop{ioc}; static void onReadStdout(boost::system::error_code const& ec, std::size_t size) { if (!ec) { std::cout << "onReadStdout size: " << size; std::istream is{&stdoutBuf}; std::string line; if (std::getline(is, line)) { std::cout << ", data: " << line; } std::cout << std::endl; boost::asio::async_read_until(aop, stdoutBuf, '\n', [] (boost::system::error_code const& err, std::size_t count) { onReadStdout(err, count); }); } else { if (ec != boost::asio::error::eof) { std::cout << "onReadStdout ERROR size: " << size << ", error: " << ec << " (" << ec.message() << ")" << std::endl; } } } int main() try { std::cout.exceptions(std::ios_base::badbit); while (true) { std::cout << "=== BEGIN ===" << std::endl; boost::process::child child{"/usr/bin/ls", ioc, boost::process::std_out > aop}; boost::asio::async_read_until(aop, stdoutBuf, '\n', [] (boost::system::error_code const& ec, std::size_t count) { onReadStdout(ec, count); }); ioc.run(); ioc.restart(); child.wait(); aop = boost::process::async_pipe{ioc}; std::cout << "=== END ===" << std::endl; } return EXIT_SUCCESS; } catch (std::exception const& err) { std::cerr << "ERROR: " << err.what() << std::endl; return EXIT_FAILURE; }
Jetzt wüsste ich gern, was ich falsch mache.
-
Die Lösung ist sehr simpel. Einfach mal das
std::endl
im Code durch"\n"
ersetzen, und dann läuft das Programm.std::endl
macht nicht nur einen Zeilenumbruch, sondern flusht auch jedesmal den Ausgabestrom.
-
@john-0 Du hast recht. So scheint es zu laufen…
Frage mich nur warum? Irgendwann muss der interne buffer doch geflusht werden (sprich es wird der
write
syscall aufgerufen) und wenn gerade dort das Signal ankommt, müsste daswrite
ja ebenso fehlschlagen. Ich lasse das Testprogramm mal ein paar Stunden laufen, vielleicht stürzt es ja noch irgendwann ab.Ich hab noch ein bisschen herumprobiert und das Signal, was da kommt ist
SIGCHLD
. Es liegt tatsächlich anboost::process
, denn dort wird genau auf dieses Signal gewartet. Da standardmäßig fast alle Signale einen Prozess terminieren, wird es wohl in 99,9999% aller Programme nicht auffallen, dass ab und zu mal IO Funktionen einen Fehler zurückliefern.SIGCHLD
wird standardmäßig ignoriert, d.h.EINTR
wird bei den syscalls gar nicht produziert, aber sobald man auf dieses Signal wartet, kannEINTR
auftreten.
-
endl
durch'\n'
zu ersetzen hilft, denn das Programm läuft nun seit gut zwei Tagen ohne Absturz. Hat jemand eine Erklärung? Oder ist das flushen nun so super selten geworden, dass es mega unwahrscheinlich geworden istSIGCHLD
in dem gleichen Augenblick wie daswrite
zu erhalten? Das ist zumindest meine Vermutung und für meinen Anwendungsfall leider nicht akzeptabel, da das Programm monatelang ohne Neustart laufen soll und nicht zufällig aufhören soll Ausgaben zu produzieren.
Interessant ist auch, wenn ich die Ausgabe vom Terminal in eine Datei leite (normale Datei oder auch /dev/null), stürzt es auch mitendl
nicht ab.