Thread Rating:
  • 0 Votes - 0 Average
  • 1
  • 2
  • 3
  • 4
  • 5
AssertionFailed fatal error
13-01-2014, 08:01 AM
Post: #1
AssertionFailed fatal error
A MinimServer user has reported an ohNet fatal error crash with the following message:

Unhandled exception AssertionFailed at OpenHome/Queue.cpp:179 in thread DS 2

The code that caused this message is:

Code:
if (aEntry.iPrev || aEntry.iNext) {
    iMutex.Signal();
    ASSERTS();
}

Do you have any suggestions for what might cause this? Is it possible to add more information to the fatal error message that might help with problem determination?
Find all posts by this user
13-01-2014, 11:15 AM
Post: #2
RE: AssertionFailed fatal error
(13-01-2014 08:01 AM)simoncn Wrote:  A MinimServer user has reported an ohNet fatal error crash with the following message:

Unhandled exception AssertionFailed at OpenHome/Queue.cpp:179 in thread DS 2

Do you have any suggestions for what might cause this? Is it possible to add more information to the fatal error message that might help with problem determination?

The only user of the Queue classes I can think of is Timer. The DS 2 thread is one of the pool used by the device stack's web server. Timer interaction here happens for every HTTP read and for subscribe/renew/unsubscribe.

Windows or Mac builds should also report a call stack at this point; Linux builds don't. Seeing a call stack would tell us which of these timer uses was causing the crash and would enable some investigation by code review. If the crash wasn't on a NAS running Linux, do you have the call stack inside the error report?

If you don't have anything more in the crash report, do you have any other logs that hint at what was happening on device around the time of the crash? Timer code has been very stable so it'd be interesting to see whether a subnet change or other event that'll cause substantial churn to the timer queue happened just before the crash.
Find all posts by this user
13-01-2014, 04:14 PM
Post: #3
RE: AssertionFailed fatal error
(13-01-2014 11:15 AM)simonc Wrote:  The only user of the Queue classes I can think of is Timer. The DS 2 thread is one of the pool used by the device stack's web server. Timer interaction here happens for every HTTP read and for subscribe/renew/unsubscribe.

Windows or Mac builds should also report a call stack at this point; Linux builds don't. Seeing a call stack would tell us which of these timer uses was causing the crash and would enable some investigation by code review. If the crash wasn't on a NAS running Linux, do you have the call stack inside the error report?

If you don't have anything more in the crash report, do you have any other logs that hint at what was happening on device around the time of the crash? Timer code has been very stable so it'd be interesting to see whether a subnet change or other event that'll cause substantial churn to the timer queue happened just before the crash.

It was on Linux (QNAP NAS), so there's no call stack. The user reports the following activity before the crash:

Quote:I was ripping and editing records on DBpoweramp and MP3 tag editor and looking at my data base on Kinsky.

I could ask the user to run with ohNet logging enabled for a while to see if the problem occurs again. This is probably the best chance of getting more information.

Would it be difficult to produce a call stack for Linux builds? I would be willing to help with a patch for this if you could give some guidance on what would be required.
Find all posts by this user
13-01-2014, 04:26 PM
Post: #4
RE: AssertionFailed fatal error
(13-01-2014 04:14 PM)simoncn Wrote:  It was on Linux (QNAP NAS), so there's no call stack. The user reports the following activity before the crash:

Quote:I was ripping and editing records on DBpoweramp and MP3 tag editor and looking at my data base on Kinsky.

I could ask the user to run with ohNet logging enabled for a while to see if the problem occurs again. This is probably the best chance of getting more information.

Doesn't sound like anything terribly disruptive to ohNet was happening so this might be hard to reproduce. Running again with DebugLevel.kDvInvocation | DebugLevel.kDvEvent | DebugLevel.kTrace logging enabled would be interesting though.


(13-01-2014 04:14 PM)simoncn Wrote:  Would it be difficult to produce a call stack for Linux builds? I would be willing to help with a patch for this if you could give some guidance on what would be required.

The relevant code is the OsStackTrace* functions in ohNet/Os/Posix/Os.c. This thread suggests that the code that is conditionally compiled for Mac desktop should also work for Linux. If you have any interesting Linux platforms to hand, it'd be great if you could confirm this. If not, I'll have a look at it later in the week.
Find all posts by this user
13-01-2014, 05:25 PM
Post: #5
RE: AssertionFailed fatal error
(13-01-2014 04:26 PM)simonc Wrote:  Doesn't sound like anything terribly disruptive to ohNet was happening so this might be hard to reproduce. Running again with DebugLevel.kDvInvocation | DebugLevel.kDvEvent | DebugLevel.kTrace logging enabled would be interesting though.

As the problem resulted in a fatal error, it was very disruptive to MinimServer. Sad Are you suggesting that this error could have been ignored by the ohNet runtime?

Quote:The relevant code is the OsStackTrace* functions in ohNet/Os/Posix/Os.c. This thread suggests that the code that is conditionally compiled for Mac desktop should also work for Linux. If you have any interesting Linux platforms to hand, it'd be great if you could confirm this. If not, I'll have a look at it later in the week.

I have more interesting Linux platforms here than you could shake a stick at. Smile I'll try this and see what happens.
Find all posts by this user
13-01-2014, 05:33 PM
Post: #6
RE: AssertionFailed fatal error
(13-01-2014 05:25 PM)simoncn Wrote:  
(13-01-2014 04:26 PM)simonc Wrote:  Doesn't sound like anything terribly disruptive to ohNet was happening so this might be hard to reproduce. Running again with DebugLevel.kDvInvocation | DebugLevel.kDvEvent | DebugLevel.kTrace logging enabled would be interesting though.

As the problem resulted in a fatal error, it was very disruptive to MinimServer. Sad Are you suggesting that this error could have been ignored by the ohNet runtime?

I meant to say that it sounded like nothing was happening that would prompt unusual churn on ohNet's timer queue. Timer code hasn't changed much in years so I wonder whether this is a long standing but obscure bug, meaning that we might struggle to reproduce the problem to be able to investigate further.

While I agree that a crash is disruptive and should be avoided, there isn't any reliable way for ohNet to recover from this state.
Find all posts by this user
17-01-2014, 12:47 PM (This post was last modified: 17-01-2014 01:35 PM by simoncn.)
Post: #7
RE: AssertionFailed fatal error
I tried removing the #if lines as suggested. The code compiles OK, but it doesn't produce the expected result on an assertion failure. I'm getting the following output:

Code:
terminate called after throwing an instance of 'OpenHome::AssertionFailed'
Aborted

The fatal error handler wasn't called, and I don't see a stack trace anywhere. Any suggestions would be appreciated. I'll also do some investigation myself.

(17-01-2014 12:47 PM)simoncn Wrote:  
Code:
terminate called after throwing an instance of 'OpenHome::AssertionFailed'
Aborted

This is what happens if the ASSERTS() call is on a thread that wasn't started by ohNet. I moved the ASSERTS() call to a thread that was started by ohNet, and the following output was printed:

Code:
ohNet fatal error: Unhandled exception AssertionFailed at OpenHome/Net/Device/Upnp/DviServerUpnp.cpp:779 in thread DS 3

/sd1/minim/minimserver/data/native/libohNet.so(+0xe0b5c) [0x4f1e0b5c]
/sd1/minim/minimserver/data/native/libohNet.so(_ZN8OpenHome9ExceptionC2EPKcS2_j+0x34) [0x4f1711bc]
/sd1/minim/minimserver/data/native/libohNet.so(+0x71298) [0x4f171298]
/sd1/minim/minimserver/data/native/libohNet.so(_ZN8OpenHome17CallAssertHandlerEPKcj+0x18) [0x4f170f98]
/sd1/minim/minimserver/data/native/libohNet.so(+0x55bbc) [0x4f155bbc]
/sd1/minim/minimserver/data/native/libohNet.so(+0x56200) [0x4f156200]
/sd1/minim/minimserver/data/native/libohNet.so(+0xba9c8) [0x4f1ba9c8]
/sd1/minim/minimserver/data/native/libohNet.so(+0xbe1b8) [0x4f1be1b8]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd411c) [0x4f1d411c]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
Aborted

This isn't quite what I was hoping for. Sad
Find all posts by this user
17-01-2014, 01:51 PM
Post: #8
RE: AssertionFailed fatal error
(17-01-2014 12:47 PM)simoncn Wrote:  This is what happens if the ASSERTS() call is on a thread that wasn't started by ohNet. I moved the ASSERTS() call to a thread that was started by ohNet, and the following output was printed:

Code:
ohNet fatal error: Unhandled exception AssertionFailed at OpenHome/Net/Device/Upnp/DviServerUpnp.cpp:779 in thread DS 3

/sd1/minim/minimserver/data/native/libohNet.so(+0xe0b5c) [0x4f1e0b5c]
/sd1/minim/minimserver/data/native/libohNet.so(_ZN8OpenHome9ExceptionC2EPKcS2_j+0x34) [0x4f1711bc]
/sd1/minim/minimserver/data/native/libohNet.so(+0x71298) [0x4f171298]
/sd1/minim/minimserver/data/native/libohNet.so(_ZN8OpenHome17CallAssertHandlerEPKcj+0x18) [0x4f170f98]
/sd1/minim/minimserver/data/native/libohNet.so(+0x55bbc) [0x4f155bbc]
/sd1/minim/minimserver/data/native/libohNet.so(+0x56200) [0x4f156200]
/sd1/minim/minimserver/data/native/libohNet.so(+0xba9c8) [0x4f1ba9c8]
/sd1/minim/minimserver/data/native/libohNet.so(+0xbe1b8) [0x4f1be1b8]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd411c) [0x4f1d411c]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
/sd1/minim/minimserver/data/native/libohNet.so(+0xd3d34) [0x4f1d3d34]
Aborted

This isn't quite what I was hoping for. Sad

It looks like this is expected behaviour for linux, with offline processing (possibly involving gdb) being required to turn this into a readable trace. I think Mac does better; I can't figure out why yet.
Find all posts by this user


Forum Jump: