utm5 перестал работать

rauldi · Сообщение **rauldi** » Пт окт 22, 2010 11:14

День добрый.

Столкнулся со следующей проблемой: закончилось место на диске, освобождением места занимался другой человек, после utm5 перестало работать.

В логах следующее:

myserver# cat /usr/local/netup/utm5/log/main.log
ERROR : Oct 22 11:56:56 DBASQLError: MySQL Connection Error: Can't connect to local MySQL server through socket '/tmp/mysql.sock' (61)
*CRIT : Oct 22 11:56:56 DBA:Ctx: Unable to init some contexts
*CRIT : Oct 22 11:56:56 UTM5 Core: ModMap fatal init exception. Aborting
ERROR : Oct 22 11:57:26 DBASQLError: MySQL Connection Error: Can't connect to local MySQL server through socket '/tmp/mysql.sock' (61)
*CRIT : Oct 22 11:57:26 DBA:Ctx: Unable to init some contexts
*CRIT : Oct 22 11:57:26 UTM5 Core: ModMap fatal init exception. Aborting
ERROR : Oct 22 11:57:56 DBASQLError: MySQL Connection Error: Can't connect to local MySQL server through socket '/tmp/mysql.sock' (61)
*CRIT : Oct 22 11:57:56 DBA:Ctx: Unable to init some contexts
*CRIT : Oct 22 11:57:56 UTM5 Core: ModMap fatal init exception. Aborting

myserver# cat /usr/local/netup/utm5/log/debug.log
Info : Oct 22 11:56:56 UTM5 Logger: New `?Debug : ' stream: /netup/utm5/log/debug.log
Info : Oct 22 11:56:56 UTM5 Logger: New ` Info : ' stream: /netup/utm5/log/main.log
Info : Oct 22 11:56:56 UTMCtx: ctx_init_file not specified. Database encription not enabled ...
?Debug : Oct 22 11:56:56 UTMCtx: Initialization started...
Notice: Oct 22 11:56:56 ModMap: Sub-Module 'utmctx' inserted...
Info : Oct 22 11:56:56 DBA:Ctx: Creating 6 DB connections
Info : Oct 22 11:56:56 DBA:Ctx: DB Transactions are disabled
?Debug : Oct 22 11:56:56 DBCtx: Connecting to MySQL database
?Debug : Oct 22 11:56:56 DBCtx: Connection parameters username: utm5; dbname: UTM5 host: localhost
ERROR : Oct 22 11:56:56 DBASQLError: MySQL Connection Error: Can't connect to local MySQL server through socket '/tmp/mysql.sock' (61)
*CRIT : Oct 22 11:56:56 DBA:Ctx: Unable to init some contexts
Notice: Oct 22 11:56:56 ModMap: Error loading module 'dba:ctx'
*CRIT : Oct 22 11:56:56 UTM5 Core: ModMap fatal init exception. Aborting

В сообщениях почты каждые 30 секунд:

To: root@myserver.local

utm5_core process exited ... Check it

При запуске utm5_core.sh выдается следующее:

myserver# /usr/local/etc/rc.d/utm5_core.sh start
Starting utm5_core
myserver# Starting utm5_core
?Debug : Oct 22 12:10:45 Rehash: Rehash manager started
Notice: Oct 22 12:10:45 ModMap: Sub-Module 'rehash' inserted...
Notice: Oct 22 12:10:45 UTM5 Config: Processing config file: /netup/utm5/utm5.cfg
Notice: Oct 22 12:10:45 ModMap: Sub-Module 'config' inserted...
Notice: Oct 22 12:10:45 ModMap: Sub-Module 'logger' inserted...
*CRIT : Oct 22 12:10:45 DBA:Ctx: Unable to init some contexts
*CRIT : Oct 22 12:10:45 UTM5 Core: ModMap fatal init exception. Aborting
usage: kill [-s signal_name] pid ...
kill -l [exit_status]
kill -signal_name pid ...
kill -signal_number pid ...
utm5_core process exited ... mail to admin sended. Sleeping 5 sec!

Операционная система:

myserver# uname -a
FreeBSD myserver.local 5.4-RELEASE FreeBSD 5.4-RELEASE #4: Sun Sep 10 09:07:23 MSD 2006 root@myserver.local:/usr/src/sys/i386/compile/MYSERVER i386

Версия mysql:

myserver# mysql -V
mysql Ver 14.7 Distrib 4.1.10a, for portbld-freebsd5.4 (i386)

Подскажите куда смотреть, и что "ковырять".

Заранее спасибо.

Ответ в первой строке:

ERROR : Oct 22 11:56:56 DBASQLError: MySQL Connection Error: Can't connect to local MySQL server through socket '/tmp/mysql.sock' (61)

Биллинг не может соединиться с СУБД через указанный сокет. Сокет кто-то поломал...

Может кто-то освободил место из под сокета, путем его удаления...

rauldi · Сообщение **rauldi** » Пт окт 22, 2010 11:25

Chistiakov_A писал(а):Ответ в первой строке:

ERROR : Oct 22 11:56:56 DBASQLError: MySQL Connection Error: Can't connect to local MySQL server through socket '/tmp/mysql.sock' (61)

Биллинг не может соединиться с СУБД через указанный сокет. Сокет кто-то поломал...

Может кто-то освободил место из под сокета, путем его удаления...

Как правильно восстановить, не подскажите?

rauldi · Сообщение **rauldi** » Пт окт 22, 2010 13:05

Посмотрел дальше, решил убедиться что у меня запущен mysql

myserver# pgrep -lf mysql
myserver#

Дальше решил запустить его, и проверить статус:

myserver# /usr/local/etc/rc.d/mysql-server.sh start
Starting mysql.
myserver# /usr/local/etc/rc.d/mysql-server.sh status
mysql is not running.

Посмотрел логи hostname.err

101022 14:05:34 mysqld started
101022 14:05:35 InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
101022 14:05:35 InnoDB: Starting log scan based on checkpoint at
InnoDB: log sequence number 4 2004212865.
InnoDB: Error: tried to read 65536 bytes at offset 0 2630656.
InnoDB: Was only able to read -1.
101022 14:05:36 InnoDB: Operating system error number 5 in a file operation.
InnoDB: Error number 5 means 'Input/output error'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/mysql/en/Opera ... codes.html
InnoDB: File operation call: 'read'.
InnoDB: Cannot continue operation.
101022 14:05:36 mysqld ended

и попробовал найти файл mysql.sock

myserver# find / | grep mysql.sock
/tmp/mysql.sock
myserver#

Думаю дальше, не откажусь от любых подсказок.

Спецы говорят, что лог Вашего MySQL сервера очень похож на то, что СУБД не стартует из-за повреждений, похожих на повреждения жесткого диска и рекомендуют посмотреть, что пишется в dmesg

rauldi · Сообщение **rauldi** » Пт окт 22, 2010 13:40

К сожалению данного лога не нашёл.

В /var/log было совершенно всё удаленно.

myserver# ls -la /var/log
total 14
drwxrwxrwx 2 root wheel 512 Oct 21 07:06 .
drwxr-xr-x 25 root wheel 512 Oct 22 18:33 ..
-rw-r--r-- 1 root wheel 0 Oct 21 07:06 httpsd-access.log
-rw-r--r-- 1 root wheel 3770 Oct 22 14:34 httpsd-error.log
-rw-r--r-- 1 root wheel 28 Oct 22 14:37 lastlog
-rw------- 1 root wheel 24 Oct 21 07:06 pflog
-rw-r--r-- 1 root wheel 23 Oct 22 14:34 snmpd.log

rauldi · Сообщение **rauldi** » Пт окт 22, 2010 13:46

Запустил

Copyright (c) 1992-2005 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
The Regents of the University of California. All rights reserved.
FreeBSD 5.4-RELEASE #4: Sun Sep 10 09:07:23 MSD 2006
root@myserver.local:/usr/src/sys/i386/compile/MYSERVER
ACPI APIC Table: <VIA694 MSI ACPI>
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: AMD Athlon(tm) XP 1800+ (1499.84-MHz 686-class CPU)
Origin = "AuthenticAMD" Id = 0x662 Stepping = 2
Features=0x383fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE>
AMD Features=0xc0400000<AMIE,DSP,3DNow!>
real memory = 536805376 (511 MB)
avail memory = 515063808 (491 MB)
ioapic0 <Version 1.1> irqs 0-23 on motherboard
npx0: <math processor> on motherboard
npx0: INT 16 interface
acpi0: <VIA694 MSI ACPI> on motherboard
acpi0: Power Button (fixed)
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x4008-0x400b on acpi0
cpu0: <ACPI CPU (3 Cx states)> on acpi0
acpi_button0: <Power Button> on acpi0
acpi_button1: <Sleep Button> on acpi0
pcib0: <ACPI Host-PCI bridge> port 0x6000-0x607f,0x5000-0x500f,0x4080-0x40ff,0x4000-0x407f,0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
agp0: <VIA 82C8363 (Apollo KT133x/KM133) host to PCI bridge> mem 0xd4000000-0xd43fffff at device 0.0 on pci0
pcib1: <PCI-PCI bridge> at device 1.0 on pci0
pci1: <PCI bus> on pcib1
pci1: <display, VGA> at device 0.0 (no driver attached)
isab0: <PCI-ISA bridge> at device 7.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <VIA 82C686B UDMA100 controller> port 0xd000-0xd00f,0x376,0x170-0x177,0x3f6,0x1f0-0x1f7 at device 7.1 on pci0
atapci0: Correcting VIA config for southbridge data corruption bug
ata0: channel #0 on atapci0
ata1: channel #1 on atapci0
xl0: <3Com 3c905B-TX Fast Etherlink XL> port 0xdc00-0xdc7f mem 0xd4400000-0xd440007f irq 19 at device 10.0 on pci0
miibus0: <MII bus> on xl0
xlphy0: <3Com internal media interface> on miibus0
xlphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
xl0: Ethernet address: 00:50:04:a1:bd:4b
xl1: <3Com 3c905C-TX Fast Etherlink XL> port 0xe000-0xe07f mem 0xd4401000-0xd440107f irq 18 at device 13.0 on pci0
miibus1: <MII bus> on xl1
ukphy0: <Generic IEEE 802.3u media interface> on miibus1
ukphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
xl1: Ethernet address: 00:01:02:fc:d6:d2
fdc0: <floppy drive controller> port 0x3f7,0x3f0-0x3f5 irq 6 drq 2 on acpi0
sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
sio0: type 16550A
sio1: <16550A-compatible COM port> port 0x2f8-0x2ff irq 3 on acpi0
sio1: type 16550A
ppc0: <Standard parallel printer port> port 0x378-0x37f irq 7 on acpi0
ppc0: Generic chipset (EPP/NIBBLE) in COMPATIBLE mode
ppbus0: <Parallel port bus> on ppc0
plip0: <PLIP network interface> on ppbus0
lpt0: <Printer> on ppbus0
lpt0: Interrupt-driven port
ppi0: <Parallel I/O> on ppbus0
atkbdc0: <Keyboard controller (i8042)> port 0x64,0x60 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
orm0: <ISA Option ROMs> at iomem 0xc9000-0xc97ff,0xc8000-0xc87ff,0xc0000-0xc7fff on isa0
pmtimer0 on isa0
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Timecounter "TSC" frequency 1499839446 Hz quality 800
Timecounters tick every 10.000 msec
ad0: 114473MB <SAMSUNG SP1253N/BU100-45> [232581/16/63] at ata0-master UDMA100
Mounting root from ufs:/dev/ad0s1a
pflog0: promiscuous mode enabled
ad0: FAILURE - READ_DMA status=51<READY,DSC,ERROR> error=40<UNCORRECTABLE> LBA=160297727

Последняя строчка FAILURE

Pulse · Сообщение **Pulse** » Пт окт 22, 2010 14:00

а fsck ?

serjk · Сообщение **serjk** » Пт окт 22, 2010 14:00

rauldi писал(а):Запустил
ad0: FAILURE - READ_DMA status=51<READY,DSC,ERROR> error=40<UNCORRECTABLE> LBA=160297727
Последняя строчка FAILURE

бэд-блоки на жестком диске, судя по всему. Меняйте диск, восстанавливайте базу из бекапа. Если на сервере был настроен RAID, разбирайтесь с ним.

rauldi · Сообщение **rauldi** » Пт окт 22, 2010 14:08

** /dev/ad0s1a (NO WRITE)
** Last Mounted on /
** Root file system
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
1473 files, 78880 used, 47959 free (407 frags, 5944 blocks, 0.3% fragmentation)
** /dev/ad0s1e (NO WRITE)
** Last Mounted on /tmp
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
UNREF FILE I=8 OWNER=root MODE=100600
SIZE=48 MTIME=Oct 22 15:07 2010
CLEAR? no

** Phase 5 - Check Cyl groups
FREE BLK COUNT(S) WRONG IN SUPERBLK
SALVAGE? no

SUMMARY INFORMATION BAD
SALVAGE? no

BLK(S) MISSING IN BIT MAPS
SALVAGE? no

10 files, 10 used, 126829 free (29 frags, 15850 blocks, 0.0% fragmentation)
** /dev/ad0s1f (NO WRITE)
** Last Mounted on /usr
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
** Phase 5 - Check Cyl groups
FREE BLK COUNT(S) WRONG IN SUPERBLK
SALVAGE? no

462147 files, 9145929 used, 46741090 free (329322 frags, 5801471 blocks, 0.6% fragmentation)
** /dev/ad0s1d (NO WRITE)
** Last Mounted on /var
** Phase 1 - Check Blocks and Sizes
** Phase 2 - Check Pathnames
** Phase 3 - Check Connectivity
** Phase 4 - Check Reference Counts
UNREF FILE I=17043 OWNER=root MODE=140666
SIZE=0 MTIME=Oct 22 14:33 2010
CLEAR? no

UNREF FILE I=17054 OWNER=smmsp MODE=100660
SIZE=38 MTIME=Oct 22 15:08 2010
RECONNECT? no

CLEAR? no

UNREF FILE I=17060 OWNER=smmsp MODE=100660
SIZE=498 MTIME=Oct 22 15:08 2010
RECONNECT? no

CLEAR? no

UNREF FILE I=17083 OWNER=root MODE=100644
SIZE=4 MTIME=Oct 22 15:08 2010
RECONNECT? no

CLEAR? no

UNREF FILE I=17086 OWNER=smmsp MODE=100660
SIZE=38 MTIME=Oct 22 15:08 2010
RECONNECT? no

CLEAR? no

UNREF FILE I=17088 OWNER=smmsp MODE=100660
SIZE=498 MTIME=Oct 22 15:08 2010
RECONNECT? no

CLEAR? no

UNREF FILE I=17089 OWNER=root MODE=100600
SIZE=38 MTIME=Oct 22 15:08 2010
RECONNECT? no

CLEAR? no

UNREF FILE I=17091 OWNER=root MODE=100600
SIZE=803 MTIME=Oct 22 15:08 2010
RECONNECT? no

CLEAR? no

** Phase 5 - Check Cyl groups
FREE BLK COUNT(S) WRONG IN SUPERBLK
SALVAGE? no

SUMMARY INFORMATION BAD
SALVAGE? no

BLK(S) MISSING IN BIT MAPS
SALVAGE? no

806 files, 15895 used, 110941 free (101 frags, 13855 blocks, 0.1% fragmentation)

да ладно, давите SALVAGE, чо уж там... хуже не будет

Pulse · Сообщение **Pulse** » Пт окт 22, 2010 14:14

топикстартеру следует знать, что для успешности надо загрузиться в singleusermode

rauldi · Сообщение **rauldi** » Пт окт 22, 2010 15:00

Прошу прощения, нахожусь на удаленной площадке, в данный момент в single mode перевести не получится.
К сожалению на этой машине поддержки удаленного доступа нет (имею ввиду как ILO у HP)

rauldi · Сообщение **rauldi** » Пт окт 22, 2010 15:17

Добавление fsck_y_enable="YES"

в /etc/rc.conf

не поможет?

Может привести к тому, что в процессе загрузки застрянет и будет ждать указаний с клавиатуры, что делать с найденной проблемой