Hi,
Thank you for your help!
Private inheritance of Scope was a mistake.
But ScopeTimer was really just an experiment, it's not used anywhere in the code.
clearJob() has a DEBUG_ENTRY macro:
bool JobPathEditor::clearJob()
{
DEBUG_ENTRY;
...
}
bool JobPathEditor::clearJob()
{
DEBUG_ENTRY;
...
}
To copy to clipboard, switch view to plain text mode
So it's just a:
Scope DBG(__PRETTY_FUNCTION__);
Scope DBG(__PRETTY_FUNCTION__);
To copy to clipboard, switch view to plain text mode
On the stack and the constructor calls qDebug(). No timers involved.
My guess is that the problem might be stackLevel variable, but I don't know how.
Previously it was declared in scopedebug.h as following:
extern uint stackLevel;
extern uint stackLevel;
To copy to clipboard, switch view to plain text mode
And in scopedebug.cpp it was initializet:
uint stackLevel = 0;
uint stackLevel = 0;
To copy to clipboard, switch view to plain text mode
Since I started using QThreadPool I tried to change stackLevel to be thread_local although I'm using it only in the main thread. So now it's defined only in the cpp file:
static uint thread_local stackLevel = 0;
static uint thread_local stackLevel = 0;
To copy to clipboard, switch view to plain text mode
The program crashes the same!
The program is quite big so I cannot post the whole source and small QThreadPool experiments are not crashing.
I forgot to add that I override the message handler to generate a log file.
Q_GLOBAL_STATIC
(QFile, gLogFile
);
static QtMessageHandler defaultHandler;
void myMessageOutput
(QtMsgType type,
const QMessageLogContext
&context,
const QString &msg
) {
//const QString fmt = QStringLiteral("%1: %2 (%3:%4, %5)\n");
static const QString fmt
= QStringLiteral
("%1: %2\n");
switch (type) {
case QtDebugMsg:
str = fmt.arg(QStringLiteral("Debug")).arg(msg); //.arg(context.file).arg(context.line).arg(context.function);
break;
case QtInfoMsg:
str = fmt.arg(QStringLiteral("Info")).arg(msg); //.arg(context.file).arg(context.line).arg(context.function);
break;
case QtWarningMsg:
str = fmt.arg(QStringLiteral("Warning")).arg(msg); //.arg(context.file).arg(context.line).arg(context.function);
break;
case QtCriticalMsg:
str = fmt.arg(QStringLiteral("Critical")).arg(msg); //.arg(context.file).arg(context.line).arg(context.function);
break;
case QtFatalMsg:
str = fmt.arg(QStringLiteral("Fatal")).arg(msg); //.arg(context.file).arg(context.line).arg(context.function);
}
s << str;
defaultHandler(type, context, msg);
}
//Called in main() right after QApplication constructor
void setupLogger()
{
const QString path
= qApp
->applicationDirPath
();
QFile *logFile
= gLogFile
();
logFile->setFileName(path + QStringLiteral("/logs/fremolog.log"));
if(!logFile->isOpen())
{
dir.mkdir("logs");
}
if(logFile->isOpen())
{
defaultHandler = qInstallMessageHandler(myMessageOutput);
}
else {
qDebug() << "Cannot open Log file:" << logFile->fileName() << "Error:" << logFile->errorString();
}
}
Q_GLOBAL_STATIC(QFile, gLogFile);
static QtMessageHandler defaultHandler;
void myMessageOutput(QtMsgType type, const QMessageLogContext &context, const QString &msg)
{
QString str;
//const QString fmt = QStringLiteral("%1: %2 (%3:%4, %5)\n");
static const QString fmt = QStringLiteral("%1: %2\n");
switch (type) {
case QtDebugMsg:
str = fmt.arg(QStringLiteral("Debug")).arg(msg); //.arg(context.file).arg(context.line).arg(context.function);
break;
case QtInfoMsg:
str = fmt.arg(QStringLiteral("Info")).arg(msg); //.arg(context.file).arg(context.line).arg(context.function);
break;
case QtWarningMsg:
str = fmt.arg(QStringLiteral("Warning")).arg(msg); //.arg(context.file).arg(context.line).arg(context.function);
break;
case QtCriticalMsg:
str = fmt.arg(QStringLiteral("Critical")).arg(msg); //.arg(context.file).arg(context.line).arg(context.function);
break;
case QtFatalMsg:
str = fmt.arg(QStringLiteral("Fatal")).arg(msg); //.arg(context.file).arg(context.line).arg(context.function);
}
QTextStream s(gLogFile());
s << str;
defaultHandler(type, context, msg);
}
//Called in main() right after QApplication constructor
void setupLogger()
{
const QString path = qApp->applicationDirPath();
QFile *logFile = gLogFile();
logFile->setFileName(path + QStringLiteral("/logs/fremolog.log"));
logFile->open(QFile::WriteOnly | QFile::Append | QFile::Text);
if(!logFile->isOpen())
{
QDir dir(path);
dir.mkdir("logs");
logFile->open(QFile::WriteOnly | QFile::Append | QFile::Text);
}
if(logFile->isOpen())
{
defaultHandler = qInstallMessageHandler(myMessageOutput);
}
else {
qDebug() << "Cannot open Log file:" << logFile->fileName() << "Error:" << logFile->errorString();
}
}
To copy to clipboard, switch view to plain text mode
Then when QTextStrem is destoyed (myMessageOutput returns) it calls flush() of QFileDevice
bool QFileDevice::flush()
{
Q_D(QFileDevice);
if (!d->fileEngine) {
qWarning("QFileDevice::flush: No file engine. Is IODevice open?");
return false;
}
if (!d->writeBuffer.isEmpty()) {
qint64 size = d->writeBuffer.nextDataBlockSize();
qint64 written = d->fileEngine->write(d->writeBuffer.readPointer(), size);
if (written > 0)
d->writeBuffer.free(written); //CRASH here
//size is <optimized out> and written is always 78 when the program crashes.
bool QFileDevice::flush()
{
Q_D(QFileDevice);
if (!d->fileEngine) {
qWarning("QFileDevice::flush: No file engine. Is IODevice open?");
return false;
}
if (!d->writeBuffer.isEmpty()) {
qint64 size = d->writeBuffer.nextDataBlockSize();
qint64 written = d->fileEngine->write(d->writeBuffer.readPointer(), size);
if (written > 0)
d->writeBuffer.free(written); //CRASH here
//size is <optimized out> and written is always 78 when the program crashes.
To copy to clipboard, switch view to plain text mode
Then in QIODvicePrivate::RingBufferRef::free()
inline void free(qint64 bytes) { Q_ASSERT(m_buf); m_buf->free(bytes); }
//m_buf is valid:
//basicBlockSize = 16384
//bufferSize = 0
//buffers has 1 item
//this QRingChunk items has:
//headOffset = 0
//tailOffset = 0
//QByteArray chunk = "Debug: Starting WORKER: rs check\r\nDebug: >>> bool JobPathEditor::clearJob()\nW_32bit2-Debug/test_new_edit_system.db\"\r\n?"
//NOTE: I escaped the characters as Qt Creator shows them. The QByteArray is long 16384 bytes and after the last \r\n thera are a lot of ? characters
inline void free(qint64 bytes) { Q_ASSERT(m_buf); m_buf->free(bytes); }
//m_buf is valid:
//basicBlockSize = 16384
//bufferSize = 0
//buffers has 1 item
//this QRingChunk items has:
//headOffset = 0
//tailOffset = 0
//QByteArray chunk = "Debug: Starting WORKER: rs check\r\nDebug: >>> bool JobPathEditor::clearJob()\nW_32bit2-Debug/test_new_edit_system.db\"\r\n?"
//NOTE: I escaped the characters as Qt Creator shows them. The QByteArray is long 16384 bytes and after the last \r\n thera are a lot of ? characters
To copy to clipboard, switch view to plain text mode
So here two messages are concatenated: "Starting WORKER: rs check" from the QRunnable::run() in a thread and " >>> bool JobPathEditor::clearJob()" from the min thread in Scope constructor.
I don't now the origin of "W_32bit2-Debug/test_new_edit_system.db" it is never printed neither in Qt Creator console neither in the log file.
It's the last portion of the path of the file opened by the program but I don't know how it ended there.
The file path is printed when loading the file but it's in a completely different part of the code and happens way before. In the middle qDebug() is used multiple times.
The full message is: Loading: "C:/Filippo/Qt_project/build-fremo_db_5-Desktop_Qt_5_11_3_MinGW_32bit2-Debug/test_new_edit_system.db"
Finally:
void QRingBuffer::free(qint64 bytes)
{
Q_ASSERT(bytes <= bufferSize); //Fails with bytes = 78 and bufferSize = 0
...
void QRingBuffer::free(qint64 bytes)
{
Q_ASSERT(bytes <= bufferSize); //Fails with bytes = 78 and bufferSize = 0
...
To copy to clipboard, switch view to plain text mode
The assert failure always happens in the main thread and myMessageOutput is called from the main thread but only with the second message: " >>> bool JobPathEditor::clearJob()"
Maybe the problem is the globally shared QFile not thread safe?
If so how should I change the code?
Bookmarks