X fails to start about half the time on bootup

Help with booting MiniMyth

Moderator: Pablo

m_theredhead
Contributor
Posts: 170
Joined: Thu Apr 27, 2006 7:00 pm
Location: Arizona

Re: X fails to start about half the time on bootup

Post by m_theredhead » Sun Jul 29, 2012 5:12 pm

I just booted -81. It took about 6-7 times from mythwelcome before mythfrontend would start.


Jul 29 09:06:58 mythliv mythwelcome: 2012-07-29 09:06:58.354493 I Unlocking input devices
Jul 29 09:06:58 mythliv mythwelcome: 2012-07-29 09:06:58.413237 I Locking input devices
Jul 29 09:06:59 mythliv kernel: mythfrontend[1920]: segfault at 4 ip b3a879b7 sp abc7ecf4 error 4 in libdbus-1.so.3[b3a4e000+57000]
Jul 29 09:06:59 mythliv mythwelcome: 2012-07-29 09:06:59.898289 I Locking input devices
Jul 29 09:07:00 mythliv mythwelcome: 2012-07-29 09:07:00.761075 I Unlocking input devices
Jul 29 09:07:00 mythliv mythwelcome: 2012-07-29 09:07:00.777704 I Unlocking input devices
Jul 29 09:07:10 mythliv mythwelcome: 2012-07-29 09:07:10.770459 I Locking input devices
Jul 29 09:07:12 mythliv mythwelcome: 2012-07-29 09:07:12.299293 I Locking input devices
Jul 29 09:07:13 mythliv mythwelcome: 2012-07-29 09:07:13.096948 I Unlocking input devices
Jul 29 09:07:13 mythliv mythwelcome: 2012-07-29 09:07:13.113590 I Unlocking input devices
Jul 29 09:07:18 mythliv mythwelcome: 2012-07-29 09:07:17.970162 I Locking input devices
Jul 29 09:07:19 mythliv mythwelcome: 2012-07-29 09:07:19.640689 I Locking input devices
Jul 29 09:07:20 mythliv mythwelcome: 2012-07-29 09:07:20.516696 I Unlocking input devices
Jul 29 09:07:20 mythliv mythwelcome: 2012-07-29 09:07:20.533252 I Unlocking input devices
Jul 29 09:07:26 mythliv mythwelcome: 2012-07-29 09:07:26.003018 I Locking input devices
Jul 29 09:07:27 mythliv mythwelcome: 2012-07-29 09:07:27.230603 I Locking input devices
Jul 29 09:07:28 mythliv mythwelcome: 2012-07-29 09:07:28.112958 I Unlocking input devices
Jul 29 09:07:28 mythliv mythwelcome: 2012-07-29 09:07:28.129573 I Unlocking input devices
Jul 29 09:07:30 mythliv mythwelcome: 2012-07-29 09:07:30.662862 I Locking input devices
Jul 29 09:07:31 mythliv kernel: mythfrontend[2090]: segfault at 0 ip b3a29e5b sp abc3ede0 error 4 in libdbus-1.so.3[b3a07000+57000]
Jul 29 09:07:31 mythliv mythwelcome: 2012-07-29 09:07:31.936134 I Locking input devices
Jul 29 09:07:32 mythliv mythwelcome: 2012-07-29 09:07:32.699381 I Unlocking input devices
Jul 29 09:07:32 mythliv mythwelcome: 2012-07-29 09:07:32.712680 I Unlocking input devices
.....

brown_m_k
Member
Posts: 45
Joined: Fri May 08, 2009 2:00 am

Re: X fails to start about half the time on bootup

Post by brown_m_k » Mon Aug 13, 2012 2:54 am

Hi folks!

I have a frontend running 0.25.2-81 which has the same problem with failing to boot to X most of the time. I have to login to it via SSH and start x one or two times before it'll go. Seems to be related to dbus, as I have seen dbus segfaulting and mythfrontend failures shortly after. I have two other frontends that are unaffected.

The affected system is a Gigabyte motherboard, on board AMD Radeon graphics which have been disabled and replaced with an Nvidia G210. The remote receiver is a Hauppage MCE USB transceiver (1784:0001 TopSeed Technology Corp. eHome Infrared Transceiver)

Here's one of the segfaults I saw yesterday.

Code: Select all

Aug 11 21:50:41 intrepid mythfrontend: 2012-08-11 21:50:41.246810 I  Starting IO manager (write)
Aug 11 21:50:41 intrepid mythfrontend: 2012-08-11 21:50:41.246838 I  Starting IO manager (read)
Aug 11 21:50:41 intrepid mythfrontend: 2012-08-11 21:50:41.426792 N  Setting QT default locale to EN_US
Aug 11 21:50:41 intrepid mythfrontend: 2012-08-11 21:50:41.426830 I  Current locale EN_US
Aug 11 21:50:41 intrepid mythfrontend: 2012-08-11 21:50:41.429167 N  Reading locale defaults from /usr/share/mythtv//locales/en_us.xml
Aug 11 21:50:41 intrepid mythfrontend: 2012-08-11 21:50:41.567799 I  ScreenSaverX11Private: XScreenSaver support enabled
Aug 11 21:50:41 intrepid mythfrontend: 2012-08-11 21:50:41.568869 I  ScreenSaverX11Private: DPMS is disabled.
Aug 11 21:50:41 intrepid mythfrontend: 2012-08-11 21:50:41.618571 N  Desktop video mode: 1920x1080 60.000 Hz
Aug 11 21:50:41 intrepid mythfrontend: 2012-08-11 21:50:41.787966 I  Listening on TCP 127.0.0.1:6547
Aug 11 21:50:41 intrepid mythfrontend: 2012-08-11 21:50:41.788146 I  Listening on TCP 192.168.2.23:6547
Aug 11 21:50:42 intrepid kernel: mythfrontend[2003]: segfault at 16f ip 0000016f sp ab83e9fc error 4 in mythfrontend[8048000+1fb000]
some other dbus errors in Myth yesterday

Code: Select all

Aug 11 21:59:16 intrepid mythfrontend: 2012-08-11 21:59:16.484883 A  MMUnix:CheckMountable: DBus interface error: The name org.freedesktop.UDisks was not provided by any.service files
Aug 11 21:59:17 intrepid mythfrontend: 2012-08-11 21:59:16.989498 A  MMUnix:CheckMountable: DBus interface error: The name org.freedesktop.UDisks was not provided by any.service files
Aug 11 21:59:17 intrepid mythfrontend: 2012-08-11 21:59:17.492595 A  MMUnix:CheckMountable: DBus interface error: The name org.freedesktop.UDisks was not provided by any.service files

Code: Select all

Aug 11 22:17:23 intrepid mythfrontend: 2012: assertion failed "_DBUS_ALIGN_ADDRESS (data, 4) == data" file "dbus-marshal-basic.c" line 241 function _dbus_unpack_uint32
Aug 11 22:17:23 intrepid mythfrontend: File "dbus-timeout.c" line 344 process 2012 should not have been reached: Nonexistent timeout was removed
Aug 11 22:17:23 intrepid mythfrontend: 2012-08-11 22:17:23.841077 I  Loading en_us translation for module mythfrontend
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x35a92) [0xb39e0a92]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x3607e) [0xb39e107e]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x1d66c) [0xb39c866c]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x12512) [0xb39bd512]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x1258a) [0xb39bd58a]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x3b9d9) [0xb39e69d9]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x188fb) [0xb39c38fb]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x311f1) [0xb39dc1f1]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x82af) [0xb39b32af]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(dbus_pending_call_block+0x1ac) [0xb39c3b18]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(dbus_connection_send_with_reply_and_block+0x20d) [0xb39d182a]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libavahi-client.so.3(+0x822c) [0xb1b7422c]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libavahi-client.so.3(avahi_entry_group_new+0x1a6) [0xb1b744f2]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libdns_sd.so.1(DNSServiceRegister+0
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libmythbase-0.25.so.0(_ZN15BonjourR
egister8RegisterEtRK10QByteArrayS2_S2_+0x222) [0xb6f33aaa]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libmythtv-0.25.so.0(_ZN17MythAirplayServer5StartEv+0x3e7) [0xb73af09d]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/libmythtv-0.25.so.0(+0x4bc1f5) [0xb74d21f5]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/qt4/lib/libQtCore.so.4(_ZN11QMetaObject8activateEP7QObjectPKS_iPPv+0x3d2) [0xb5f4a87a]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/qt4/lib/libQtCore.so.4(_ZN7QThread7startedEv+0x22) [0xb5f79ae0]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/qt4/lib/libQtCore.so.4(+0x6340a) [0xb5ea240a]
Aug 11 22:17:23 intrepid mythfrontend:   /usr/lib/nvidia/libGL.so.1(+0x8ab41) [0xb4bb9b41]
Aug 11 22:17:23 intrepid mythfrontend:   [0x5c8b0824]

Code: Select all

Aug 11 22:18:39 intrepid mythfrontend: 2012-08-11 22:18:39.410393 I  ScreenSaverX11Private: DPMS is disabled.
Aug 11 22:18:39 intrepid mythfrontend: 2012-08-11 22:18:39.439071 N  Desktop video mode: 1920x1080 60.000 Hz
Aug 11 22:18:39 intrepid mythfrontend: 2012-08-11 22:18:39.500709 I  Listening on TCP 127.0.0.1:6547
Aug 11 22:18:39 intrepid mythfrontend: 2012-08-11 22:18:39.501123 I  Listening on TCP 192.168.2.23:6547
Aug 11 22:18:40 intrepid kernel: mythfrontend[2144]: segfault at 4 ip b39cef72 sp abfce7c4 error 6 in libdbus-1.so.3[b3998000+57000]
Here are the dbus errors I've seen today (grep dbus)

Code: Select all

Aug 12 20:54:18 intrepid minimyth: initializing dbus ...
Aug 12 20:54:18 intrepid minimyth: starting dbus daemon ...
Aug 12 20:54:26 intrepid mythfrontend: 2019: assertion failed "(real)->len <= ((real)->allocated - _DBUS_STRING_ALLOCATION_PADDING)" file "dbus-string.c" line 719 function _dbus_string_get_length
Aug 12 20:54:26 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x35a92) [0xb39b1a92]
Aug 12 20:54:26 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x3607e) [0xb39b207e]
Aug 12 20:54:26 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x3615d) [0xb39b215d]
Aug 12 20:54:26 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x2a6f7) [0xb39a66f7]
Aug 12 20:54:26 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x18036) [0xb3994036]
Aug 12 20:54:26 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x3107c) [0xb39ad07c]
Aug 12 20:54:26 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x82af) [0xb39842af]
Aug 12 20:54:26 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x17911) [0xb3993911]
Aug 12 20:54:26 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x179af) [0xb39939af]
Aug 12 20:54:26 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(dbus_connection_send_with_reply+0x4e1) [0xb39955e3]
Aug 12 20:54:26 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(dbus_connection_send_with_reply_and_block+0x1c1) [0xb39a27de]
Aug 12 20:55:22 intrepid mythfrontend: File "dbus-timeout.c" line 344 process 2132 should not have been reached: Nonexistent timeout was removed
Aug 12 20:55:22 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x35a92) [0xb3a84a92]
Aug 12 20:55:22 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x3607e) [0xb3a8507e]
Aug 12 20:55:22 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x1d66c) [0xb3a6c66c]
Aug 12 20:55:22 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x12512) [0xb3a61512]
Aug 12 20:55:22 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x1258a) [0xb3a6158a]
Aug 12 20:55:22 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x3b9d9) [0xb3a8a9d9]
Aug 12 20:55:22 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x188fb) [0xb3a678fb]
Aug 12 20:55:22 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x311f1) [0xb3a801f1]
Aug 12 20:55:22 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(+0x82af) [0xb3a572af]
Aug 12 20:55:22 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(dbus_pending_call_block+0x1ac) [0xb3a67b18]
Aug 12 20:55:22 intrepid mythfrontend:   /usr/lib/libdbus-1.so.3(dbus_connection_send_with_reply_and_block+0x20d) [0xb3a7582a]
Given all that, Me thinks something is broken in dbus...

HTH!

/Mike

brown_m_k
Member
Posts: 45
Joined: Fri May 08, 2009 2:00 am

Re: X fails to start about half the time on bootup

Post by brown_m_k » Mon Aug 13, 2012 4:38 am

A quick and dirty hack to work around the X issue to improve the WAF:

check_mythfrontend.sh

Code: Select all

#!/bin/bash

PROCESS_NUM=$(ps -ef |grep /usr/bin/mythfrontend | grep -v "grep" | wc -l)
echo $PROCESS_NUM
if [ $PROCESS_NUM -eq "1" ];
then
        exit 0
else
        mm_service x stop && mm_service x start
fi
A crontab file:

Code: Select all

# m h  dom mon dow user   command
*/1 * * * * /usr/local/bin/check_mythfrontend,sh > /dev/null 2>&1
And a little addition to minimyth.pm

Code: Select all

$minimyth->confro_get('check_mythfrontend.sh', '/usr/local/bin/check_mythfrontend.sh');
    chmod(0755, '/usr/local/bin/check_mythfrontend.sh');
Set MM_CRON_FETCH_CRONTAB='yes' in minimyth.conf, and get yourself some simple process monitoring to improve the WAF. Some assembly required. I had to whip this up temporarily, as my wife has been getting annoyed staring at the flashing white cursor rather than her soaps...

HTH!

/Mike

m_theredhead
Contributor
Posts: 170
Joined: Thu Apr 27, 2006 7:00 pm
Location: Arizona

Re: X fails to start about half the time on bootup

Post by m_theredhead » Mon Aug 13, 2012 4:08 pm

Mike,

Did you try the mythwelcome solution mentioned earlier in the thread? I think that would give you an even higher WAF factor as X isn't restarting when mythfrontend fails to start.

It is working well for me.

Michael

brown_m_k
Member
Posts: 45
Joined: Fri May 08, 2009 2:00 am

Re: X fails to start about half the time on bootup

Post by brown_m_k » Tue Aug 14, 2012 3:30 am

m_theredhead wrote: Did you try the mythwelcome solution mentioned earlier in the thread? I think that would give you an even higher WAF factor as X isn't restarting when mythfrontend fails to start.
Michael,

Thanks, I had seen the MythWelcome solution. I use it on a frontend/backend with tuners in the family room normally, so that people can see that Myth is actually doing something when it starts up on it's own. One thing I noticed, is that when you exit the frontend, it hangs and never drops back to the MythWelcome screen. I'll have to explore the idle timer feature, as I run a cronjob on that system every 10 minutes that checks if frontend is running, and if not (and not busy come flagging or running other jobs), will set the wake time and shutdown)

Similarly, I can't exit a frontend that has booted to Mythfrontend; that also hangs. I went the route I did because my wife will expect it to work the way it did, so it's easier to work around problems with the system, than it is to change my wife's expectations. I'm still trying to figure out ACPI wake issues with the video card, so I'm fixing things the most expedient way possible.

Thanks!

/Mike

m_theredhead
Contributor
Posts: 170
Joined: Thu Apr 27, 2006 7:00 pm
Location: Arizona

Re: X fails to start about half the time on bootup

Post by m_theredhead » Tue Aug 14, 2012 4:59 am

Hello,

That makes sense.

We have different usage models. I boot minimyth diskless and it starts mythwelcome. Mythwelcome starts mythfrontend and loops if it crashes. One mythfrontend starts, it never stops. I have myth configured to never exist from the frontend. From here out, the machines just gets put to sleep and wakes up as need be. Only if it crashes or there is a minimyth upgrade do I do the boot cycle again.

Michael

brown_m_k
Member
Posts: 45
Joined: Fri May 08, 2009 2:00 am

Possible cause of X fails to start about half the time on bo

Post by brown_m_k » Fri Aug 17, 2012 4:03 am

Folks,

I may have discovered a possible cause of X failing to start. I certainly found the cause of weird behaviours I've been suffering from, some of which existed under 0.24-76, and worsened with the upgrade to 0.25.2-81. I had one frontend which would not send system events (to trigger lighting scenes on play/pause), except the first time I configured it, or blew away and reset the frontend settings, yet others with the exact same config would fire those events. Under 0.25.2-81, I had problems with LIRC failing to start, X failing to start, couldn't exit frontend to mythwelcome, external commands intermittently not working, etc. I've been tearing my hear out on this for a while. After a lot of troubleshooting, I figured it had to do with frontend settings, so I commented out some MM_MYTHDB_KEYBINDINGS and MM_MYTHDB_JUMPPOINTS statements in my -common.conf

Lo and behold, system events are now firing on the one that wasn't, and I can exit MythFrontend to MythWelcome. I have to test a few other things, so I can't speak to X or LIRC working better yet. But, I did find it's fixing some weird problems that have been ongoing for a while, so I thought I'd bring it to some folks attention. Could be that you have some old settings causing some problems.

HTH!

/Mike

m_theredhead
Contributor
Posts: 170
Joined: Thu Apr 27, 2006 7:00 pm
Location: Arizona

Re: X fails to start about half the time on bootup

Post by m_theredhead » Mon Dec 10, 2012 8:18 pm

FYI,

This is still happening with 0.26.0-82 although I can't get any new error messages due to the logging issue. Once that is working again I will try to post an update.

Post Reply