No DB access for web admin and DCERouter doesn't start

[chrisbirkinshaw]

Yesterday my system filled up to 100% on the root partition and stopped working. I cleared out some files and rebooted, but when I tried to access the web admin I got:

Fatal error: mysql error: [1044: Access denied for user ''@'localhost' to database 'pluto_main'] in CONNECT(, '****', '****', pluto_main) in /var/www/lmce-admin/include/adodb/adodb-errorhandler.inc.php on line 77

This seemed very odd! I went into mysql and added permissions:

grant all on pluto_main.* to  ''@'localhost';
flush privileges;

The webadmin then gave me a similar message for pluto_media, so I repeated the above for that database.

Now the web admin worked! Phew. But, when I restarted the system again the DCERouter does not start. I see the following in the Launch Manager log:

Code: [Select]

10 03/29/10 10:53:54.662 Starting... <0xb71476c0>
10 03/29/10 10:53:54.662 =>initialize_Connections() <0xb71476c0>
10 03/29/10 10:53:54.675 Opening DB connection.. <0xb71476c0>
10 03/29/10 10:53:54.702 Successful <0xb71476c0>
05 03/29/10 10:53:54.713 Detected core as device #1 <0xb71476c0>
10 03/29/10 10:53:54.713 =>initialize_VideoSettings() <0xb71476c0>
10 03/29/10 10:53:54.713 =>initialize_AudioSettings() <0xb71476c0>
10 03/29/10 10:53:54.714 =>initialize_LogOptions() <0xb71476c0>
10 03/29/10 10:53:54.715 =>initialize_Start() <0xb71476c0>
10 03/29/10 10:53:54.715 Checking for mysql... <0xb71476c0>
10 03/29/10 10:53:54.715 Done checking for mysql...connection OK <0xb71476c0>
10 03/29/10 10:53:54.715 Checking for core services... <0xb71476c0>
10 03/29/10 10:53:54.715 Checking if core is up... <0xb71476c0>
10 03/29/10 10:53:54.741 No router lock file found, core is down <0xb71476c0>
10 03/29/10 10:53:54.741 Done checking for core services...core is not running <0xb71476c0>
10 03/29/10 10:53:54.741 AlarmManager::AddRelativeAlarm current time 1269856434 delay 5 type 2 <0xb71476c0>
10 03/29/10 10:53:54.742 AlarmManager::AddAbsoluteAlarm time 1269856439 type 2 <0xb71476c0>
21 03/29/10 10:53:54.742 lock(0x895737c) (>4) alarm: AlarmManager.cpp:185  <0xb71476c0>
21 03/29/10 10:53:54.742 acquired(0x895737c) #0 (>4) alarm AlarmManager.cpp:185  <0xb71476c0>
21 03/29/10 10:53:54.744 unlock(0x895737c) #0 (>4) alarm: AlarmManager.cpp:185  <0xb71476c0>
21 03/29/10 10:53:54.744 removed from map (0x895737c) #1 (>4) alarm: AlarmManager.cpp:185  was: 3 size, now 2 Rel: Y Got: Y <0xb71476c0>
21 03/29/10 10:53:54.744 end cond wait AlarmManager.cpp:102 (0x895737c)  <0xb7146b90>
21 03/29/10 10:53:54.754 start cond 0x89573b4 timed wait till 1269856439.0 now 1269856434.754391000 AlarmManager.cpp:102 (0x895737c)  <0xb7146b90>
21 03/29/10 10:53:54.755 end cond wait AlarmManager.cpp:102 (0x895737c)  <0xb6945b90>
21 03/29/10 10:53:54.755 start cond wait AlarmManager.cpp:102 (0x895737c)  <0xb6945b90>



Hmm. So I manually started the DCERouter and the App_Server in separate terminal sessions and a lot of stuff comes to life, however I see some stuff in their logs I have never seen before.

DCERouter:

Code: [Select]

This program is distributed according to the terms of the GNU Public License, available at:
http://www.fsf.org/licensing/licenses/gpl.html
This program is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY;
without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
See the GNU Public License for more details.
---------------

21 03/29/10 9:23:43.550 lock(0x8887bac) (>2) messagequeue: DCERouter.cpp:1862  <0xb65a5b90>
21 03/29/10 9:23:43.551 acquired(0x8887bac) #0 (>2) messagequeue DCERouter.cpp:1862  <0xb65a5b90>
10 03/29/10 9:23:43.551 ProcessQueue going to sleep <0xb65a5b90>
21 03/29/10 9:23:43.552 start cond wait DCERouter.cpp:1862 (0x8887bac)  <0xb65a5b90>
10 03/29/10 9:23:43.633 Running as device: 2 installation: 1005237 using path: /usr/pluto/ <0xb65a66c0>
10 03/29/10 9:23:43.634 AlarmManager::AlarmManager 0x88a4dd8 <0xb65a66c0>
21 03/29/10 9:23:43.634 lock(0x88a4e1c) (>3) alarm: AlarmManager.cpp:87  <0xb65a66c0>
21 03/29/10 9:23:43.634 acquired(0x88a4e1c) #0 (>3) alarm AlarmManager.cpp:87  <0xb65a66c0>
21 03/29/10 9:23:43.634 unlock(0x88a4e1c) #0 (>3) alarm: AlarmManager.cpp:87  <0xb65a66c0>
21 03/29/10 9:23:43.634 removed from map (0x88a4e1c) #0 (>3) alarm: AlarmManager.cpp:87  was: 2 size, now 1 Rel: Y Got: Y <0xb65a66c0>
21 03/29/10 9:23:43.635 lock(0x88a4e1c) (>4) alarm: AlarmManager.cpp:102  <0xb5bffb90>
21 03/29/10 9:23:43.635 acquired(0x88a4e1c) #0 (>4) alarm AlarmManager.cpp:102  <0xb5bffb90>
21 03/29/10 9:23:43.635 start cond wait AlarmManager.cpp:102 (0x88a4e1c)  <0xb5bffb90>
21 03/29/10 9:23:43.635 lock(0x88a4e1c) (>6) alarm: AlarmManager.cpp:102  <0xb4bfdb90>
21 03/29/10 9:23:43.636 acquired(0x88a4e1c) #0 (>6) alarm AlarmManager.cpp:102  <0xb4bfdb90>
21 03/29/10 9:23:43.636 start cond wait AlarmManager.cpp:102 (0x88a4e1c)  <0xb4bfdb90>
21 03/29/10 9:23:43.636 lock(0x88a4e1c) (>7) alarm: AlarmManager.cpp:102  <0xb43fcb90>
21 03/29/10 9:23:43.636 acquired(0x88a4e1c) #0 (>7) alarm AlarmManager.cpp:102  <0xb43fcb90>
21 03/29/10 9:23:43.636 start cond wait AlarmManager.cpp:102 (0x88a4e1c)  <0xb43fcb90>
21 03/29/10 9:23:43.635 lock(0x88a4e1c) (>5) alarm: AlarmManager.cpp:102  <0xb53feb90>
21 03/29/10 9:23:43.646 acquired(0x88a4e1c) #0 (>5) alarm AlarmManager.cpp:102  <0xb53feb90>
21 03/29/10 9:23:43.646 start cond wait AlarmManager.cpp:102 (0x88a4e1c)  <0xb53feb90>
10 03/29/10 9:23:43.672 Executed query UPDATE Device SET Registered=0,psc_mod=psc_mod (39 rows) <0xb65a66c0>
10 03/29/10 9:23:43.678 Executed query UPDATE Device JOIN Device AS Parent ON Device.FK_Device_ControlledVia=Parent.PK_Device SET Device.FK_Installation=Parent.FK_Installation (0 rows) <0xb65a66c0>
10 03/29/10 9:23:46.084 Created the server device: 1 CORE <0xb65a66c0>


App Server:

Code: [Select]

App_Server, v.2.0.0.44.09112922522
Visit www.plutohome.com for source code and license information

10 03/29/10 9:25:01.470 Device: 0 starting.  Connecting to: dcerouter <0xb6fc56c0>
10 03/29/10 9:25:01.517 Setting timeout for socket 4 to 20 <0xb6fc56c0>
10 03/29/10 9:25:01.598 ALSA Master volume: 66% <0xb6fc56c0>
10 03/29/10 9:25:01.598 Starting signal handler thread <0xb6fc56c0>
10 03/29/10 9:25:01.598 Started signal handler thread <0xb6fc56c0>
21 03/29/10 9:25:01.599 lock(0x8cb3ab4) (>81) MessageQueue: Command_Impl.cpp:822  <0xb67c3b90>
21 03/29/10 9:25:01.599 acquired(0x8cb3ab4) #0 (>81) MessageQueue Command_Impl.cpp:822  <0xb67c3b90>
21 03/29/10 9:25:01.599 start cond wait Command_Impl.cpp:822 (0x8cb3ab4)  <0xb67c3b90>
10 03/29/10 9:25:01.613 Requesthandler 0x8cb3968 (device: 1) runThread now running <0xb5fc2b90>
10 03/29/10 9:25:01.613 Connect OK <0xb6fc56c0>
05 03/29/10 9:25:01.613 Creating child 2 <0xb6fc56c0>
10 03/29/10 9:25:01.613 Got CreateEvent for unknown type 1. <0xb6fc56c0>
05 03/29/10 9:25:01.613 Note: Device manager has attached a device of type 1 that this has no custom event handler for.  It will not fire events. <0xb6fc56c0>
10 03/29/10 9:25:01.613 Got CreateCommand for unknown type 1. <0xb6fc56c0>
05 03/29/10 9:25:01.613 Note: Device manager has attached a device of type 1 that this has no custom handler for.  This is normal for IR. <0xb6fc56c0>
05 03/29/10 9:25:01.613 Creating child 3 <0xb6fc56c0>
10 03/29/10 9:25:01.614 Spawning device: 3 File_Grids_Plugin on display:  ip: 192.168.80.1 <0xb6fc56c0>
10 03/29/10 9:25:01.598 SignalHandler_Thread: Started <0xb6fc4b90>
Linux signal handler: Started
Linux signal handler: Exited
10 03/29/10 9:25:01.639 SignalHandler_Action: Started <0xb6fc4b90>
21 03/29/10 9:25:01.639 lock(0x8cf2dac) (>88) MessageQueue: Command_Impl.cpp:357  <0xb6fc56c0>
21 03/29/10 9:25:01.639 acquired(0x8cf2dac) #0 (>88) MessageQueue Command_Impl.cpp:357  <0xb6fc56c0>
21 03/29/10 9:25:01.639 unlock(0x8cf2dac) #0 (>88) MessageQueue: Command_Impl.cpp:357  <0xb6fc56c0>
21 03/29/10 9:25:01.640 removed from map (0x8cf2dac) #0 (>88) MessageQueue: Command_Impl.cpp:357  was: 4 size, now 3 Rel: Y Got: Y <0xb6fc56c0>
05 03/29/10 9:25:01.640 Creating child 4 <0xb6fc56c0>
10 03/29/10 9:25:01.640 Spawning device: 4 General_Info_Plugin on display:  ip: 192.168.80.1 <0xb6fc56c0>
21 03/29/10 9:25:01.639 lock(0x8cb3b84) (>89) AppServer: SignalHandler.cpp:74  <0xb6fc4b90>
21 03/29/10 9:25:01.654 acquired(0x8cb3b84) #0 (>89) AppServer SignalHandler.cpp:74  <0xb6fc4b90>
10 03/29/10 9:25:01.654 SignalHandler_Action: Exited <0xb6fc4b90>
21 03/29/10 9:25:01.654 unlock(0x8cb3b84) #0 (>89) AppServer: SignalHandler.cpp:74  <0xb6fc4b90>
21 03/29/10 9:25:01.654 removed from map (0x8cb3b84) #0 (>89) AppServer: SignalHandler.cpp:74  was: 3 size, now 2 Rel: Y Got: Y <0xb6fc4b90>
Linux signal handler: Started
Linux signal handler: Exited


It looks to me like something odd is going on. Can anyone comment on this?

Thanks,

Chris

[merkur2k]

basically, the /etc/pluto.conf file has been truncated. it contains stuff specific to the system so its pretty difficult to repair. reinstalling is probably the best option.

[chrisbirkinshaw]

Oh, yes, it does look short! Any ideas how this has happened? Is this a common problem? Should I file a ticket to improve logging in this situation?

Can you send me yours? It's worth a go...!

Thanks,

Chris

[merkur2k]

the problem is probably because of too much logging. there are a couple bugs that can lead to logs getting out of control, such as unplugging a hid device (keyboard or mouse) while the system is running. some other process apparently continually writes the pluto.conf file, so when there is no space it ends up getting truncated.
for what its worth, heres my config file:

# Pluto config file
MySqlHost = localhost
MySqlUser = root
MySqlPassword =
MySqlDBName = pluto_main
DCERouter = localhost
MySqlPort = 3306
DCERouterPort = 3450
PK_Device = 1
Activation_Code = 1111
PK_Installation = 1004672
PK_Users = 1
PK_Distro = 17
Display = 0
SharedDesktop = 1
OfflineMode = false
#<-mkr_b_videowizard_b->
UseVideoWizard = 1
#<-mkr_b_videowizard_e->
LogLevels = 1,5,7,8
#ImmediatelyFlushLog = 1
AutostartCore=1
AutostartMedia=1
PlutoVersion = 2.0.0.44.10011622689
Bookmark_Media = 4,5
RA_CheckRemotePort = 1
TimeZoneSet = 1
AVWizardOverride = 0
AVWizardDone = 1
FirstBoot = false
DesktopActivated = 1
DVDKeysCache = /home/.dvdcss
DisableFirewall=1
LastSearchTokenUpdate=1269922924

some stuff you may have to pull out of the database such as the installation id.

[golgoj4]

this also worked for me. Sudden power loss then no db / web access. Following these steps fixed the problem.

*Note: i left installation id empty.

[mythtified]

I am curious as to why the pluto.conf file was truncated.  Does it get overwritten each time there is a reload router?

[golgoj4]

this is dont know. I do know that the .conf file had all sorts of crazyness in it referring to hard drives and other stuff. Looked nothing like what merk posted. Just happy it worked @ 3:30am when i was ready to keel someone.

-golgoj4

[jamesh]

This thread saved me a bunch of time as I didn't have to rebuild my core from scratch. I copied the pluto config file above, got the PK_Installation and PlutoVersion values from the DB, and it worked great from there. Thank you merkur2k!