TestAlarmClock.General failed #15801

mvhulten · 2019-03-22T20:26:36Z

Bug report

Describe the bug

Building Kodi 18.1 on Guix failed because of a failed test:

        Start 417: TestAlarmClock.General
417/520 Test #417: TestAlarmClock.General ...................................................Child aborted***Exception:   0.42 sec
Note: Google Test filter = TestAlarmClock.General
[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
[----------] 1 test from TestAlarmClock
[ RUN      ] TestAlarmClock.General
[       OK ] TestAlarmClock.General (0 ms)
[----------] 1 test from TestAlarmClock (0 ms total)

[----------] Global test environment tear-down
[==========] 1 test from 1 test case ran. (284 ms total)
[  PASSED  ] 1 test.
Clean shutdown of TestGlobalPattern1
kodi-test: ../nptl/pthread_mutex_lock.c:425: __pthread_mutex_lock_full: Assertion `INTERNAL_SYSCALL_ERRNO (e, __err) != ESRCH || !robust' failed.

Expected Behavior

Kodi building with all tests passing.

Actual Behavior

Test # 417 did not pass.

To Reproduce

guix pull
guix package -i kodi

Debuglog

The buildlog can be found here:

xgwxv3x9fhxx2rabyxr4mwwyh55lj9-kodi-18.1.drv.log

Screenshots

n/a

Additional context or screenshots (if appropriate)

n/a

Your Environment

GNU/Linux

Used Operating system:

Operating system version/name: GuixSD, current.
Kodi version: 18.1

The text was updated successfully, but these errors were encountered:

xbmc-gh-bot · 2019-03-22T20:26:40Z

Thank you for using Kodi and our issue tracker. This is your friendly Kodi GitHub bot 😉

It seems that you have not followed the template we provide and require for all bug reports (or have opened a roadmap item by accident). Please understand that following the template is mandatory and required for the team to be able handle the volume of open issues efficiently.

Please edit your issue message to follow our template and make sure to fill in all fields appropriately. The issue will be closed after one week has passed without satisfactory follow-up from your side.

This is an automatically generated message. If you believe it was sent in error, please say so and a team member will remove the "Ignored rules" label.

xbmc-gh-bot · 2019-03-22T20:26:41Z

Thank you for using Kodi and our issue tracker. This is your friendly Kodi GitHub bot 😉

The issue that you have opened was marked as ignoring the rules of our bug tracker by a team member. Please review the following requirements for issue reports and make sure that you follow all of them:

Reports must follow our template and have all relevant fields filled in.
A full debug log is always mandatory.
- Make sure that you restart Kodi after setting the log level to debug.
- Log files may not be modified except for the removal of personally identifying information, usernames/passwords and similar.
- For build errors, include a full build log instead.
You may not have any unsupported add-ons installed. If possible, reproduce on a clean Kodi installation or at least remove all offending add-ons.

Please understand that adherence to these rules is required for the team to be able to handle the volume of open issues efficiently. The issue will be closed after one week has passed without satisfactory follow-up from your side.

yol · 2019-03-23T13:46:10Z

Sorry for the double message of the bot, that has been fixed.

Did you by any chance just try to build/make test twice? I'm afraid the test suite can be a bit flaky at times.

mvhulten · 2019-03-23T19:46:07Z

Yes, I tried again, and now it passes all tests.

Any ideas why it is not deterministic/reproducible? Otherwise, I guess we should close this issue.

yol · 2019-03-24T13:55:56Z

Guess our threading implementation has some problems.
I'm not sure whether it's worth to invest time into since most of it is slated for replacmenent anyway (#13721)

[----------] 1 test from TestAlarmClock
[ RUN      ] TestAlarmClock.General
LLVMSymbolizer: error reading file: No such file or directory
==================
WARNING: ThreadSanitizer: data race (pid=3365)
  Write of size 1 at 0x7ffc6a95b910 by main thread:
    #0 pthread_mutex_destroy <null> (kodi-test+0x16633bf)
    #1 XbmcThreads::CRecursiveMutex::~CRecursiveMutex() /home/philipp/gsoc/xbmc/xbmc/threads/platform/RecursiveMutex.h:32:33 (kodi-test+0x18472c8)
    #2 XbmcThreads::CountingLockable<XbmcThreads::CRecursiveMutex>::~CountingLockable() /home/philipp/gsoc/xbmc/xbmc/threads/Lockables.h:35:27 (kodi-test+0x1847288)
    #3 CCriticalSection::~CCriticalSection() /home/philipp/gsoc/xbmc/xbmc/threads/CriticalSection.h:14:7 (kodi-test+0x1845aa8)
    #4 CThread::~CThread() /home/philipp/gsoc/xbmc/xbmc/threads/Thread.cpp:67:1 (kodi-test+0x286d94b)
    #5 CAlarmClock::~CAlarmClock() /home/philipp/gsoc/xbmc/xbmc/utils/AlarmClock.cpp:29:27 (kodi-test+0x266961f)
    #6 TestAlarmClock_General_Test::TestBody() /home/philipp/gsoc/xbmc/xbmc/utils/test/TestAlarmClock.cpp:25:1 (kodi-test+0x195176f)
[...]

  Previous atomic read of size 1 at 0x7ffc6a95b910 by thread T5 (mutexes: write M1109996555266799888):
    #0 pthread_mutex_unlock <null> (kodi-test+0x1660f5f)
    #1 XbmcThreads::CRecursiveMutex::unlock() /home/philipp/gsoc/xbmc/xbmc/threads/platform/RecursiveMutex.h:36:28 (kodi-test+0x1847a88)
    #2 XbmcThreads::CountingLockable<XbmcThreads::CRecursiveMutex>::unlock() /home/philipp/gsoc/xbmc/xbmc/threads/Lockables.h:51:43 (kodi-test+0x1847a51)
    #3 XbmcThreads::UniqueLock<CCriticalSection>::unlock() /home/philipp/gsoc/xbmc/xbmc/threads/Lockables.h:129:46 (kodi-test+0x1af89d9)
    #4 CSingleLock::Leave() /home/philipp/gsoc/xbmc/xbmc/threads/SingleLock.h:29:25 (kodi-test+0x1af82e8)
    #5 CThread::staticThread(void*) /home/philipp/gsoc/xbmc/xbmc/threads/Thread.cpp:125:8 (kodi-test+0x286c037)

  Location is stack of main thread.

  Location is global '??' at 0x7ffc6a93e000 ([stack]+0x00000001d910)

  Mutex M1109996555266799888 is already destroyed.

  Thread T5 'AlarmClock' (tid=3380, running) created by main thread at:
    #0 pthread_create <null> (kodi-test+0x1649707)
    #1 CThread::SpawnThread(unsigned int) /home/philipp/gsoc/xbmc/xbmc/threads/platform/pthreads/ThreadImpl.cpp:64:7 (kodi-test+0x286bd13)
    #2 CThread::Create(bool, unsigned int) /home/philipp/gsoc/xbmc/xbmc/threads/Thread.cpp:85:3 (kodi-test+0x286dc0f)
    #3 CAlarmClock::Start(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, float, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool, bool) /home/philipp/gsoc/xbmc/xbmc/utils/AlarmClock.cpp:44:5 (kodi-test+0x2669819)
    #4 TestAlarmClock_General_Test::TestBody() /home/philipp/gsoc/xbmc/xbmc/utils/test/TestAlarmClock.cpp:18:5 (kodi-test+0x19504fb)
[...]

SUMMARY: ThreadSanitizer: data race (/home/philipp/gsoc/xbmc/cmake-build-debug/kodi-test+0x16633bf) in pthread_mutex_destroy
==================
==================
WARNING: ThreadSanitizer: data race (pid=3365)
  Write of size 1 at 0x7ffc6a95b798 by main thread:
    #0 pthread_mutex_destroy <null> (kodi-test+0x16633bf)
    #1 XbmcThreads::CRecursiveMutex::~CRecursiveMutex() /home/philipp/gsoc/xbmc/xbmc/threads/platform/RecursiveMutex.h:32:33 (kodi-test+0x18472c8)
    #2 XbmcThreads::CountingLockable<XbmcThreads::CRecursiveMutex>::~CountingLockable() /home/philipp/gsoc/xbmc/xbmc/threads/Lockables.h:35:27 (kodi-test+0x1847288)
    #3 CCriticalSection::~CCriticalSection() /home/philipp/gsoc/xbmc/xbmc/threads/CriticalSection.h:14:7 (kodi-test+0x1845aa8)
    #4 CEvent::~CEvent() /home/philipp/gsoc/xbmc/xbmc/threads/Event.h:34:7 (kodi-test+0x195b5c9)
    #5 CThread::~CThread() /home/philipp/gsoc/xbmc/xbmc/threads/Thread.cpp:67:1 (kodi-test+0x286d96f)
    #6 CAlarmClock::~CAlarmClock() /home/philipp/gsoc/xbmc/xbmc/utils/AlarmClock.cpp:29:27 (kodi-test+0x266961f)
[...]

  Previous atomic read of size 1 at 0x7ffc6a95b798 by thread T5 (mutexes: write M1109996555266799888):
    #0 pthread_mutex_lock <null> (kodi-test+0x16728f3)
    #1 XbmcThreads::CRecursiveMutex::lock() /home/philipp/gsoc/xbmc/xbmc/threads/platform/RecursiveMutex.h:34:26 (kodi-test+0x1847248)
    #2 XbmcThreads::CountingLockable<XbmcThreads::CRecursiveMutex>::lock() /home/philipp/gsoc/xbmc/xbmc/threads/Lockables.h:49:32 (kodi-test+0x1845a4c)
    #3 XbmcThreads::UniqueLock<CCriticalSection>::UniqueLock(CCriticalSection&) /home/philipp/gsoc/xbmc/xbmc/threads/Lockables.h:118:83 (kodi-test+0x18475e3)
    #4 CSingleLock::CSingleLock(CCriticalSection&) /home/philipp/gsoc/xbmc/xbmc/threads/SingleLock.h:27:55 (kodi-test+0x18474c8)
    #5 CEvent::Set() /home/philipp/gsoc/xbmc/xbmc/threads/Event.cpp:54:15 (kodi-test+0x2865bba)
    #6 CThread::staticThread(void*) /home/philipp/gsoc/xbmc/xbmc/threads/Thread.cpp:122:24 (kodi-test+0x286c01b)

  Location is stack of main thread.

  Location is global '??' at 0x7ffc6a93e000 ([stack]+0x00000001d798)

  Mutex M1109996555266799888 is already destroyed.

  Thread T5 'AlarmClock' (tid=3380, finished) created by main thread at:
    #0 pthread_create <null> (kodi-test+0x1649707)
    #1 CThread::SpawnThread(unsigned int) /home/philipp/gsoc/xbmc/xbmc/threads/platform/pthreads/ThreadImpl.cpp:64:7 (kodi-test+0x286bd13)
    #2 CThread::Create(bool, unsigned int) /home/philipp/gsoc/xbmc/xbmc/threads/Thread.cpp:85:3 (kodi-test+0x286dc0f)
    #3 CAlarmClock::Start(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, float, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool, bool) /home/philipp/gsoc/xbmc/xbmc/utils/AlarmClock.cpp:44:5 (kodi-test+0x2669819)
    #4 TestAlarmClock_General_Test::TestBody() /home/philipp/gsoc/xbmc/xbmc/utils/test/TestAlarmClock.cpp:18:5 (kodi-test+0x19504fb)
[...]

SUMMARY: ThreadSanitizer: data race (/home/philipp/gsoc/xbmc/cmake-build-debug/kodi-test+0x16633bf) in pthread_mutex_destroy
==================
[       OK ] TestAlarmClock.General (25 ms)
[----------] 1 test from TestAlarmClock (25 ms total)

davilla · 2019-03-24T16:05:22Z

smells like same problem I ran into with CEvent

davilla · 2019-03-24T16:38:27Z

#15762

fritsch · 2019-03-24T17:35:36Z

@mvhulten Can you try: http://paste.ubuntu.com/p/wXHWG8QNWq/ this?

I know it's ugly - but we are in progress of replacing current thread impl with std threads, therefore any major rework will only add new issues :-)

FernetMenta · 2019-03-24T18:02:10Z

@fritsch this won't help. Try moving this line https://github.com/xbmc/xbmc/blob/master/xbmc/threads/Thread.cpp#L122
down after the lock (m_CriticalSection) is left.

fritsch · 2019-03-24T18:06:12Z

My workaround tries something else, this guy here is holding the lock: https://github.com/xbmc/xbmc/blob/master/xbmc/threads/Thread.cpp#L119

It then sets the event, which causes https://github.com/xbmc/xbmc/blob/master/xbmc/threads/Thread.cpp#L154 to continue, which then causes the CThread Object going out of scope, deleting the m_criticalSection.

So the workaround asks the WaitForThreadExit method to grab the m_CriticalSection again which it can only get after https://github.com/xbmc/xbmc/blob/master/xbmc/threads/Thread.cpp#L125 has has called leave()

FernetMenta · 2019-03-24T18:17:30Z

right

yol · 2019-03-25T08:26:49Z

@fritsch ThreadSanitizer is happy with that solution. It also seems to fix the second race on CEvent destruction (did not look at it more closely). Now the only races left in the test suite are those that are designed as races such as https://github.com/xbmc/xbmc/blob/master/xbmc/threads/test/TestSharedSection.cpp#L88-L89

Please move the locking into CThread::StopThread so WinThreads also benefits from this and PR :-)

fritsch · 2019-03-25T08:47:47Z

Could you try this: http://paste.ubuntu.com/p/sfDjKhZ45v/

yol · 2019-03-25T08:53:57Z

You have to put it after WaitForThreadExit. And you can't redefine lock. Just do lock.Enter(); lock.Leave(); :-)

fritsch · 2019-03-25T08:55:22Z

No - I don't have to. The SingleExit leaves the critical section and reacquires it after, when it goes out of scope.

yol · 2019-03-25T09:05:33Z

OK, how much of a difference 4 characters can make (CSingleExit vs CSingleLock) :-) Second point still stands

fritsch · 2019-03-25T09:08:12Z

See: https://github.com/xbmc/xbmc/blob/master/xbmc/Application.cpp#L258-L263

xbmc-gh-bot bot added Triage: Needed (managed by bot!) issue that was just created and needs someone looking at it Ignored rules issue that does not follow the rules (no template, missing debug log, ...) labels Mar 22, 2019

yol removed the Ignored rules issue that does not follow the rules (no template, missing debug log, ...) label Mar 23, 2019

mvhulten closed this as completed Mar 23, 2019

yol reopened this Mar 25, 2019

yol removed the Resolution: Won't fix a real bug, but the team feels that the issue is not impactful enough to spend time on label Mar 25, 2019

fritsch mentioned this issue Mar 25, 2019

CThreads: Reacquire Lock after WaitForThreadExit has finished #15810

Merged

jenkins4kodi closed this as completed in #15810 Mar 25, 2019

yol added the Resolution: Fixed issue was resolved by a code change label Mar 25, 2019

DaVukovic mentioned this issue Apr 17, 2019

Kodi 18.1 keeps crashing #15762

Closed

7 tasks

yol added this to the Leia 18.2-rc1 milestone Apr 30, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

TestAlarmClock.General failed #15801

TestAlarmClock.General failed #15801

mvhulten commented Mar 22, 2019 •

edited

xbmc-gh-bot bot commented Mar 22, 2019

xbmc-gh-bot bot commented Mar 22, 2019

yol commented Mar 23, 2019

mvhulten commented Mar 23, 2019

yol commented Mar 24, 2019

davilla commented Mar 24, 2019

davilla commented Mar 24, 2019

fritsch commented Mar 24, 2019

FernetMenta commented Mar 24, 2019

fritsch commented Mar 24, 2019

FernetMenta commented Mar 24, 2019

yol commented Mar 25, 2019

fritsch commented Mar 25, 2019

yol commented Mar 25, 2019

fritsch commented Mar 25, 2019

yol commented Mar 25, 2019

fritsch commented Mar 25, 2019

TestAlarmClock.General failed #15801

TestAlarmClock.General failed #15801

Comments

mvhulten commented Mar 22, 2019 • edited

Bug report

Describe the bug

Expected Behavior

Actual Behavior

To Reproduce

Debuglog

Screenshots

Additional context or screenshots (if appropriate)

Your Environment

xbmc-gh-bot bot commented Mar 22, 2019

xbmc-gh-bot bot commented Mar 22, 2019

yol commented Mar 23, 2019

mvhulten commented Mar 23, 2019

yol commented Mar 24, 2019

davilla commented Mar 24, 2019

davilla commented Mar 24, 2019

fritsch commented Mar 24, 2019

FernetMenta commented Mar 24, 2019

fritsch commented Mar 24, 2019

FernetMenta commented Mar 24, 2019

yol commented Mar 25, 2019

fritsch commented Mar 25, 2019

yol commented Mar 25, 2019

fritsch commented Mar 25, 2019

yol commented Mar 25, 2019

fritsch commented Mar 25, 2019

mvhulten commented Mar 22, 2019 •

edited