lis 24 2009

panic: ufs_dirbad i restarty freeBSD

Dobry administrator zawsze i dokładnie czyta logi, z akcentem na dokładnie :) .

Kilka dni temu miałem dość ciekawy przypadek automatycznego restartu serwera na skutek wykonywania prostych poleceń, np. find lub locate.
Co ciekawsze, serwer “wywalał” się zawsze na tym samym katalogu. Z początku myślałem, że to wina usługi samba i udostępnionych plików/katalogów, jednak po wnikliwym wczytaniu się w logi systemowe, przekonałem się, że byłem w błędzie.

Błąd był widoczny już w samym dmesg (logi systemowe)

/dev/ad0s1: bad dir usr 25789343 AT OFFSET 1024: MANGLED ENTRY
panic: ufs_dirbad: bad dir

Z tego wynika, że mamy do czynienia z wadliwym katalogiem usr.

Niby prosta rzecz, wchodzimy do single user mode (wtedy dyski/partycje nie są zamontowane).
Sprawdzamy tzw. mount point poleceniem

cat /etc/fstab

i traktujemy zamontowaną etykietkę (label) jako katalog /usr poleceniem fsck

# fsck -y /dev/ad0s1f

(u mnie /usr jest zamontowany jako ad0s1f).

Na koniec skanowania powinno nam się wyświetlić

***** FILE SYSTEM MARKED CLEAN *****

Po ponownym uruchomieniu serwera sprawdzamy czy wszystko jest OK przykładowymi poleceniami

# find / -type d -exec ls -ld {} ;
# find / -type d -exec stat {} ;
# find / -type d -exec touch {}/mydummyfilenamewhichshouldnotexist ;

Najwyraźniej fsck nie poradziło sobie z tym dziwnym przypadkiem, ponieważ freeBSD nadal się restartuje (panic) podczas wykonywania powyższych testów.

Na szczęście jest sposób aby to naprawić, ale może wystąpić sytuacja, że z uszkodzonego katalogu nie odzyskamy danych, aczkolwiek bądźmy dobrej myśli i miejmy pewność, że mamy zrobioną wcześniej kopię zapasową tych danych. Istotą problemu jest naprawienie systemu plików i wyeliminowanie samoistnych restartów systemu freeBSD.

Będąc ponownie w trybie single user mode uruchamiamy narzędzie fsdb (FileSystem DeBugger)

# fsdb /dev/ad0s1f
** /dev/ad0s1f
Editing file system ‘/dev/ad0s1f’
Last mounted on /mnt/ad0s1f
(…)
fsdb (inum: 2)>

Teraz wpisujemy numer tzw. inode, który bierzemy z loga (u mnie był to numer 25789343)

fsdb (inum: 2)> inode 25789343
current inode: directory
I= 25789343 MODE=40777 SIZE=1024
BTIME=May 9 12:52:12 2008 [0 nsec]
MTIME=May 9 12:52:12 2008 [0 nsec]
CTIME=May 9 12:52:12 2008 [0 nsec]
ATIME=May 9 12:52:12 2008 [0 nsec]
OWNER=root GRP=WHEEL LINKCNT=2 FLAGS=0 BLKCNT=4 GEN=157338b7
fsdb (inum: 25789343)>

Nawet gdy stracimy dane, będziemy mieli pewność, że problem zostanie usunięty.
Poleceniem clri debugując inode’a oznaczamy go jako błędny

fsdb (inum: 25789343)> clri 25789343

Wychodzimy z narzędzia debugowania.

fsdb (inum: 25789343)> quit

**** FILE SYSTEM STILL DIRTY *****
*** FILE SYSTEM MARKED DIRTY
*** BE SURE TO RUN FSDK TO CLEAN UP ANY DAMAGE
*** IF IT WAS MOUNTED, RE-MOUNT WITH -u -o reload

Będąc nadal w single user mode uruchamiamy ponownie fsck

# fsck -y /dev/ad0s1f

** /dev/ad0s1f
** Last Mounted on /usr
** Phase 1 – Check Blocks and Sizes
** Phase 2 – Check Pathnames
UNALLOCATED I= 25789343 OWNER=root MODE=0
SIZE=1024 MTIME May 9 12:52:12 2008
NAME=/_new2????

REMOVE=YES

** Phase 3 – Check Connectivity
** Phase 4 – Check Reference Counters
(…)

Podczas skanowania pojawiały się jeszcze inne różne błędy, które naprawiały się automatycznie dzięki parametrowi -y, np.

LINK COUNT DIR I=2 OWNER=root MODE=40777
SIZE=1024MTIME=May 9 12:52:12 2008 COUNT 21 SHOULD BE 20
ADJUST? yes
(…)
FREE BLK COUNT(S) WRONG IN SUPERBLK
SALVAGE? yes
(…)
SUMMARY INFORMATION BAD
SAVLAGE? yes
(…)
BLK(S) MISSING IN BIT MAPS
SALVAGE? yes

Na końcu pojawił się komunikat

***** FILE SYSTEM MARKED CLEAN *****

***** FILE SYSTEM WAS MODIFIED *****

Ale czy to wszystko? Zdecydowanie tak.
W moim przypadku było dużo szczęścia i wszystkie dane były na swoim miejscu.
Po prostu fsck jakimś dziwnym trafem nie potrafił poradzić sobie z błędnym inode o numerze 25789343.
Oczywiście ponownie przetestowałem find’em czy przypadkiem coś jeszcze nie zostało do naprawienia. Tym razem wszystko było jak należy.
Jednak gdyby nadal były restarty typu panic: ufs_dirbad: bad dir, proponuję powyższe czynności powtórzyć dla każdego złego inode’a.

Pozdrawiam


lis 18 2009

amavisd nie startuje – błąd z portem 10024

Jakiś czas temu miałem przyjemność borykać się z dziwnym problemem pakietu AMaViS’a komunikującego się z Postfix’em na portach 10024 (nasłuchiwanie AMaViS’a) i 10025 (wysyłanie odpowiedzi do Postfix’a).

Przy uruchamianiu procesu amavisd pojawia się błąd:

fox# /usr/local/etc/rc.d/amavisd start
ERROR: MISSING REQUIRED BASIC MODULES:
IO::Wrap
IO::Stringy
Unix::Syslog
Compress::Zlib
MIME::Entity
MIME::Parser
Net::Server
Net::Server::PreFork
BEGIN failed–compilation aborted at /usr/local/sbin/amavisd line 232.

Dziwnym trafem (to zapewne sprawka upgrade’owania innych portów) brakuje kilku modułów Perl’a do prawidłowego funkcjonowania pakietu AMaViS.

By rozwiązać ten problem należy wejść do konsoli Perl’a poleceniem:

perl -MCPAN -e shell

i w CPAN’ie (konsola Perl’a) instalujemy brakujące moduły (z listy powyżej) zgodnie z poleceniem

install [nazwa modułu], np. install Net::Server

Po ponownym skompilowaniu brakujących modułów (startując amavisa można zweryfikować jakich jeszcze brakuje) sprawdzamy czy nasz proces działa:

fox# /usr/local/etc/rc.d/amavisd start
Starting amavisd.
Problem in Amavis::DKIM code: Can’t locate Crypt/OpenSSL/RSA.pm in @INC (@INC contains: /usr/local/lib/perl5/5.8.9/BSDPAN /usr/local/lib/perl5/site_perl/5.8.9/mach /usr/local/lib/perl5/site_perl/5.8.9 /usr/local/lib/perl5/5.8.9/mach /usr/local/lib/perl5/5.8.9) at (eval 99) line 25.
BEGIN failed–compilation aborted at (eval 99) line 25.

Wydawać się mogło, że ponowna instalacja brakujących modułów rozwiąże problem, a tu jednak zonk.

Wobec powyższego wynika, że wsiąkł również specjalny moduł odpowiedzialny za realizację tzw. DomainKeys Identified Mail (DKIM).
Doinstalowujemy więc port

cd /usr/ports/
make search name=mail-DKIM
(…)
cd /usr/ports/mail/p5-Mail-DKIM
make install clean

I ponownie sprawdzamy czy amavisd działa

fox# /usr/local/etc/rc.d/amavisd start
Starting amavisd.
Problem in antispam SA code: Can’t locate Mail/SpamAssassin.pm in @INC (@INC contains: /usr/local/lib/perl5/5.8.9/BSDPAN /usr/local/lib/perl5/site_perl/5.8.9/mach /usr/local/lib/perl5/site_perl/5.8.9 /usr/local/lib/perl5/5.8.9/mach /usr/local/lib/perl5/5.8.9) at (eval 118) line 63.
BEGIN failed–compilation aborted at (eval 118) line 63.

Teraz łapiemy się za głowę, bowiem okazuje się, że brakuje SA (SpamAssasin’a).

Wchodzimy ponownie do konsoli Perl’a i instalujemy SA

perl -MCPAN -e shell
install Mail:SpamAssassin

Po instalacji SA uruchamiamy proces amavisd kolejny raz aby przekonać się czy jest już wszystko OK.

fox# /usr/local/etc/rc.d/amavisd start
Starting amavisd.

i sprawdzamy czy widać proces

fox# ps aux | grep amavisd
vscan 83335 3.1 3.5 79112 72304 ?? Ss 10:02AM 0:08.15 amavisd (master) (perl)
vscan 83351 0.7 3.6 82116 75068 ?? I 10:03AM 0:01.22 amavisd (ch1-avail) (perl)
vscan 83352 0.0 3.5 79744 72304 ?? I 10:03AM 0:00.03 amavisd (virgin child) (perl)
root 83359 0.0 0.0 1632 844 p0 RL+ 10:03AM 0:00.00 grep amavisd

fox# /usr/local/etc/rc.d/amavisd status
amavisd is running as pid 83335 83351 83352.

Hurra, jest sukces! Udało się! Ale… czy na pewno?
Proces działa, ale poczta nie zostaje dostarczona.

Patrzymy na logi Postfix’a

tail -f /var/log/maillog

i starając się wysłać dowolnego maila widzimy w logach następujące błędy

Oct 13 05:36:16 fox amavis[25159]: (25159-14) (!!)TROUBLE in check_mail: delivery-notification FAILED: temporarily unable to send DSN to : 450 4.4.1 Can’t connect to INET4 socket 127.0.0.1: Connection refused, MTA([127.0.0.1]:10025), id=25159-14 at /usr/local/sbin/amavisd line 11386.
Oct 13 05:36:16 fox amavis[25159]: (25159-14) (!)PRESERVING EVIDENCE in /var/amavis/tmp/amavis-20091013T030230-25159
Oct 13 05:36:16 fox postfix/smtp[29075]: 5FF9B6D42B: to=, relay=127.0.0.1[127.0.0.1]:10024, delay=1689, delays=1683/0.01/0.01/5.9, dsn=4.5.0, status=deferred (host 127.0.0.1[127.0.0.1] said: 451 4.5.0 Error in processing, id=25159-14, delivery-notification FAILED: temporarily unable to send DSN to : 450 4.4.1 Can’t connect to INET4 socket 127.0.0.1: Connection refused, MTA([127.0.0.1]:10025), id=25159-14 at /usr/local/sbin/amavisd line 11386. (in reply to end of DATA command))

Oct 13 06:05:14 fox amavis[28132]: (28132-10) (!)FWD via SMTP: -> , 450 4.4.1 Can’t connect to INET4 socket 127.0.0.1: Connection refused, MTA([127.0.0.1]:10025), id=28132-10
Oct 13 06:05:14 fox amavis[28132]: (28132-10) Blocked MTA-BLOCKED, -> , Message-ID: <20091013002640.2B90C6D425@mail.kucza.info>, mail_id: i8vzB+cdas+V, Hits: -2.235, size: 7058466, 127353 ms
Oct 13 06:05:15 fox postfix/smtp[29514]: 2B90C6D425: to=, orig_to=, relay=127.0.0.1[127.0.0.1]:10024, delay=21915, delays=21778/9.7/0.02/127, dsn=4.4.1, status=deferred (host 127.0.0.1[127.0.0.1] said: 450 4.4.1 id=28132-10 – Temporary MTA failure on relaying, Can’t connect to INET4 socket 127.0.0.1: Connection refused, MTA([127.0.0.1]:10025), id=28132-10 (in reply to end of DATA command))

Z powyższych błędów wynika, że jest jakiś problem przy połączeniu na porcie 10024.
Tutaj przyznam się bez bicia, że w configu Postfix’a zmieniłem wcześniej w celach testowych port z 10024 na 10025.

Aby nie mieszać, ustawienia plików konfiguracyjnych powinny być następujące

amavisd.conf

# Port na którym będzie nasłuchiwał AMaViS:
$inet_socket_port = 10024;
# Dopuszczaj połączenia jedynie poprzez lokalny adres IP:
@inet_acl = qw( 127.0.0.1 );

main.cf

# AMaViS
content_filter=smtp-amavis:[127.0.0.1]:10024

master.cf

smtp-amavis unix – - n – 2 smtp
-o smtp_data_done_timeout=1200
-o smtp_send_xforward_command=yes
-o disable_dns_lookups=yes

127.0.0.1:10025 inet n – n – - smtpd
-o content_filter=
-o local_recipient_maps=
-o relay_recipient_maps=
-o smtpd_restriction_classes=
-o smtpd_client_restrictions=
-o smtpd_helo_restrictions=
-o smtpd_sender_restrictions=
-o smtpd_recipient_restrictions=permit_mynetworks,reject
-o mynetworks=127.0.0.0/8
-o strict_rfc821_envelopes=yes
-o smtpd_error_sleep_time=0
-o smtpd_soft_error_limit=1001
-o smtpd_hard_error_limit=1000

Po doprowadzeniu konfiguracji pakietów Postfix + AMaViS do porządku, wszystko wróciło do normy

Oct 13 06:45:44 fox postfix/cleanup[83006]: 7DDC36D41B: message-id=<000d01ca6824$a61bc6b0$6400a8c0@morozov>
Oct 13 06:45:44 fox postfix/qmgr[38715]: 7DDC36D41B: from=, size=10257, nrcpt=1 (queue active)
Oct 13 06:45:44 fox amavis[80899]: (80899-04) (!!)WARN: all primary virus scanners failed, considering backups
Oct 13 06:45:49 fox postfix/smtpd[83003]: disconnect from unknown[113.169.91.43]
Oct 13 06:45:50 fox amavis[80899]: (80899-04) Blocked SPAM, [113.169.91.43] [113.169.91.43] -> , quarantine: spam-gAJtMJQua0NH.gz, Message-ID: <000d01ca6824$a61bc6b0$6400a8c0@morozov>, mail_id: gAJtMJQua0NH, Hits: 14.836, size: 10257, 11290 ms
Oct 13 06:45:50 fox postfix/smtp[83007]: 7DDC36D41B: to=, relay=127.0.0.1[127.0.0.1]:10024, delay=13, delays=1.6/0/0.01/11, dsn=2.5.0, status=sent (250 2.5.0 Ok, id=80899-04, DISCARD(bounce.suppressed))
Oct 13 06:45:50 fox postfix/qmgr[38715]: 7DDC36D41B: removed
Oct 13 06:45:55 fox postfix/anvil[83004]: statistics: max connection rate 1/60s for (smtp:113.23.24.227) at Oct 13 06:45:44
Oct 13 06:45:55 fox postfix/anvil[83004]: statistics: max connection count 1 for (smtp:113.23.24.227) at Oct 13 06:45:44
Oct 13 06:45:51 fox postfix/anvil[83004]: statistics: max cache size 1 at Oct 13 06:45:44

Po takim długim leczeniu choroby nasuwa się myśl: uwaga na upgrade portów :)
3mam kciuki. Pozdrawiam.


lis 5 2009

mailto z button’a

Dzisiaj coś dla developerów HTML/JavaScript i języków webowych (np. JSP/ASP/PHP).
Może dla niektórych jest to prosta rzecz, aczkolwiek kilka dłuższych chwil zajęło mi rozwiązanie tego problemu, a mianowicie jak z button’a w HTMLu można utworzyć maila w stylu takim jak link mailto

a href=”mailto:info@smartlab.pl?subject=hello world&body=hello world again!” name=”link”

Sprawa okazuje się bardzo prosta i można to zrobić następująco

INPUT TYPE=”button” VALUE=”wyślij maila” onClick=”parent.location=’mailto:adres@domena.pl?subject=to jest tytuł maila&body=a to jest treść maila’”>

Wyjaśniając powyższy kod, należy w metodzie onClick użyć parent.location i przypisać temu to co chcieliśmy wywołać w href’ie.