SERIOUS ERROR IMAP Server Da(IMAP Server Pr)

[MikeyMZ]

Hi All,

last night we had a serverhang due to a backup-problem (NOT ScalixBackup!). After reboot I am not able to access my mails via SWA.

First issue is that i can login after several tries. In the fatal-log are these outputs:

Code: Select all

19.03.2007 11:13:36 org.apache.catalina.core.ApplicationContext log
INFO: ip: 193.24.32.37; username: lollo; message: <SOAP-ENV:Fault><faultcode>SOAP-ENV:CLIENT.BadUserName</faultcode><faultstring>Dieser Benutzer konnte nicht gefunden werden oder das eingegebene Passwort ist falsch. Beachten Sie dass beim Passwort zwischen Gross- und Kleinschreibung unterschieden wird.</faultstring><detail><e:BadUserName xmlns:e="http://scalix.com/errors"><message>Dieser Benutzer konnte nicht gefunden werden oder das eingegebene Passwort ist falsch. Beachten Sie dass beim Passwort zwischen Gross- und Kleinschreibung unterschieden wird.</message><debug>user: lollo
request method(s): login
XML:
&lt;SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" SOAP-ENV:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:xsi="http://www.w3.org/1999/XMLSchema-instance" xmlns:xsd="http://www.w3.org/1999/XMLSchema"&gt;&lt;SOAP-ENV:Header&gt;&lt;credentials xmlns="http://scalix.com/schemas/gofish" SOAP-ENV:mustUnderstand="1"&gt;&lt;username&gt;lollo&lt;/username&gt;&lt;emailDomain&gt;mami.mine.nu&lt;/emailDomain&gt;&lt;fugu&gt;Ox3e6d6b603171392c232a2f333331252e24312407&lt;/fugu&gt;&lt;ts&gt;0&lt;/ts&gt;&lt;/credentials&gt;&lt;/SOAP-ENV:Header&gt;&lt;SOAP-ENV:Body&gt;&lt;m:login xmlns:m="http://scalix.com/methods"/&gt;&lt;/SOAP-ENV:Body&gt;&lt;/SOAP-ENV:Envelope&gt;&#xd;
</debug></e:BadUserName></detail></SOAP-ENV:Fault>
null
com.oddpost.soap.SoapFault: faultCode: SOAP-ENV:SERVER.MessagingException; faultString: can't open folder [#Scalix/Oddpost]

; detailName: MessagingException; detailMessage: can't open folder [#Scalix/Oddpost]

; detailDebugInfo: javax.mail.MessagingException: * BYE IMAP Server not available
        at com.sun.mail.imap.IMAPFolder.open(Unknown Source)
        at com.scalix.swa.service.MailServices.selectFolder(MailServices.java:186)
        at com.oddpost.server.mail.MailFolder.<init>(MailFolder.java:63)
        at com.oddpost.server.mail.MailFolderTree.get(MailFolderTree.java:95)
        at com.oddpost.server.objects.UserInfo.setUserProperty(UserInfo.java:229)
        at com.oddpost.server.partner.Authenticate.setLastLogin(Authenticate.java:377)
        at com.oddpost.server.module.Account.login(Account.java:73)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
        at java.lang.reflect.Method.invoke(Unknown Source)
        at com.oddpost.soap.SoapModule.invokeMethod(SoapModule.java:238)
        at com.oddpost.soap.SoapRequestImpl.execute(SoapRequestImpl.java:139)
        at com.oddpost.server.HttpRequestHandler.handleRequest(HttpRequestHandler.java:224)
        at com.oddpost.server.SoapServlet.doPost(SoapServlet.java:49)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:709)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
        at com.oddpost.server.filter.HttpConfFilter.doFilter(HttpConfFilter.java:174)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
        ... skipping the last 14 lines as irrelevant...
Caused by: com.sun.mail.iap.ConnectionException: * BYE IMAP Server not available
        at com.sun.mail.iap.Protocol.handleResult(Unknown Source)
        at com.sun.mail.imap.protocol.IMAPProtocol.select(Unknown Source)
        ... 35 more
; isHeaderFault: false; faultActor: null
        at com.oddpost.server.mail.MailFolder.<init>(MailFolder.java:65)
        at com.oddpost.server.mail.MailFolderTree.get(MailFolderTree.java:95)
        at com.oddpost.server.objects.UserInfo.setUserProperty(UserInfo.java:229)
        at com.oddpost.server.partner.Authenticate.setLastLogin(Authenticate.java:377)
        at com.oddpost.server.module.Account.login(Account.java:73)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
        at java.lang.reflect.Method.invoke(Unknown Source)
        at com.oddpost.soap.SoapModule.invokeMethod(SoapModule.java:238)
.
.
.
.
.


When I logged in then I can't access my mails.

fatal-log:

Code: Select all

SERIOUS ERROR           IMAP Server Da(IMAP Server Pr) Mon Mar 19 12:20:42 2007
[OM 10270] Process about to terminate due to error.
Signal (Segmentation Violation) trapped by process 18781
Procedure trace follows:
  -> im_OpenItem
  -> im_ItemRef2FName
  <- im_ItemRef2FName
  <- im_OpenItem
  <- sfl_OpenSfl
  <- sfl_OpenItem
  <- im_OpenItem
  -> ct_FindDITEntry
  <- ct_FindDITEntry
  -> ct_MapDITEntryToRef
  <- ct_MapDITEntryToRef
  -> ct_MatchCounts
  <- ct_MatchCounts
  -> ct_ClearRecCounts
  <- ct_ClearRecCounts
  <- ct_OpenCtner 3004
User Name: Michael Maag / medix/CN=Michael Maag
Pid of logging process: 18781
  Last Msg Subject:  (removed)
  Last Msg Sender:  (removed)
  Last Msg Id:  (removed)


SERIOUS ERROR           IMAP Server Da(IMAP Server Pr) Mon Mar 19 12:20:42 2007
[OM 10272] BACKTRACE:
/opt/scalix/lib/libom_er.so(er_add_backtrace+0xb3)[0xb7ec8d43]
/opt/scalix/lib/libom_er.so[0xb7ec902c]
/opt/scalix/lib/libom_er.so(er_DumpProcAndExit+0x1f)[0xb7ec91bf]
[0xffffe420]
/opt/scalix/lib/libom_ct.so(ct_DetachCtner+0x215)[0xb7f99fcd]
/opt/scalix/lib/libom_ual.so(ual_DeleteRecord+0x283)[0xb76cd475]
/opt/scalix/lib/libom_ual.so(ual_DeleteItem+0xa53)[0xb7702467]
/opt/scalix/lib/libom_ual.so(ual_RecvReply+0x57b)[0xb7739570]
/opt/scalix/lib/libom_tucl.so(uall_read+0x1f1)[0xb7de48dd]
/opt/scalix/lib/libom_tucl.so(ual_recv+0x44)[0xb7de0c40]
in.imap41d[0x807f05a]
in.imap41d[0x807fb7a]
in.imap41d[0x807e131]
in.imap41d[0x80630d6]
in.imap41d[0x8056e6e]
in.imap41d[0x8057d1b]
in.imap41d[0x80687ab]
in.imap41d[0x80696f1]
in.imap41d[0x80630d6]
in.imap41d[0x8064f4c]
in.imap41d[0x8065a09]
/lib/libc.so.6(__libc_start_main+0xdc)[0xb7b1787c]
in.imap41d[0x804e1a1]
User Name: Michael Maag / medix/CN=Michael Maag
Pid of logging process: 18781
  Last Msg Subject: (removed)
  Last Msg Sender:  (removed)
  Last Msg Id:  (removed)


I tried to fix a possible corruption with the omtidyu command without success.

Telneting the imap is possible:

Code: Select all

medix:~ # telnet localhost imap
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
* OK Scalix IMAP server 11.0.1.11 ready on medix.mami.mine.nu
. login lollo (removed)
. OK LOGIN completed, now connected to medix.mami.mine.nu
. logout
* BYE IMAP Server logging out
. OK LOGOUT completed
Connection closed by foreign host.


Currently I am not able to test the outlook-access.

Looking forward for suggetions.

Thanks

Michael

[ScalixSupport]

Hi Michael!

This issue has already been discussed, check the following post:
viewtopic.php?t=6295

See if this helps.

Thanks,
Subir

[MikeyMZ]

Hi,

thanks for the quick reply.

I tried the steps in the post you suggested without success.

Any more ideas?

Many thanks in advance

Michael

[ScalixSupport]

Hi Michael!

Can you restart the Scalix Server using the command s below:

Code: Select all

omshut
omrc

omshut, would shutdown the Scalix Server, while omrc, completely restarts the Scalix
Server. Check if you are able to access the SWA-Mobile page and try to login in user's
account in question.

Thanks,
Subir

[MikeyMZ]

Thanks.

But same procedure as before.

It takes 2-3 tries to log me in and then I see that there are unread messages in the folders but can't see them.

Still the same error-msgs in fatal and catalina.out as shown above

In the meanwhile I tried to omscan the mailbox w/o success.


Michael

[ScalixSupport]

Hi!

Can you send me the result of the command:

rpm -qa | grep postgres
ps -ax | grep post
omstat -a
omstat -s

Try to remove the IMAP cache for the user in question, refer to the post given earlier, this
should resolve the issue.

Thanks,
Subir

[MikeyMZ]

I wondering because it is a running system for about one month now and it runs till last night when the server hangs.

OK, here are the requested outputs:

Code: Select all

medix:~ # rpm -qa | grep postgres
postgresql-8.1.4-1.6
postgresql-server-8.1.4-1.6
scalix-postgres-11.0.1.22-1
postgresql-libs-8.1.4-1.6
medix:~ #


medix:~ # ps -ax | grep post
Warning: bad ps syntax, perhaps a bogus '-'? See http://procps.sf.net/faq.html
20138 ?        Ss     0:00 /usr/bin/postmaster -h medix.mami.mine.nu -p 5733 -D /var/opt/scalix/mx/postgres/data -k /var/opt/scalix/mx/postgres/data
20140 ?        S      0:00 postgres: logger process
20142 ?        S      0:00 postgres: writer process
20143 ?        S      0:00 postgres: stats buffer process
20144 ?        S      0:00 postgres: stats collector process
20218 ?        S      0:00 postgres: scalix scalix 192.168.0.4(54532) idle
20219 ?        S      0:00 postgres: scalix scalix 192.168.0.4(34002) idle
20220 ?        S      0:00 postgres: scalix scalix 192.168.0.4(49444) idle
20221 ?        S      0:00 postgres: scalix scalix 192.168.0.4(54498) idle
20227 ?        S      0:00 postgres: scalix scalix 192.168.0.4(55367) idle
21217 pts/6    R+     0:00 grep post


medix:~ # omstat -a
PC Monitor                    Started        NON-STOP       0
Directory Relay Server        Started        14:13:30
Notification Server           Started        14:13:30       0
Shared memory daemon          Started        NON-STOP
Notification Monitor          Started        NON-STOP
Session Monitor               Started        NON-STOP
Indexer                       Started        NON-STOP
Stats Daemon                  Started        NON-STOP
Container Access Monitor      Started        NON-STOP
Item Structure Server         Stopped
Database Monitor              Started        14:13:30
Licence Monitor Daemon        Started        NON-STOP
LDAP Daemon                   Started        14:13:30
Queue Manager                 Started        NON-STOP
Item Delete Daemon            Started        NON-STOP
IMAP Server Daemon            Started        14:13:30
SMTP Relay                    Started        14:13:30
Mime Browser Controller       Started        14:13:30
Event Server                  Started        14:13:30




medix:~ # omstat -s
Service Router                Started        14:13:31       0
Local Delivery                Started        14:13:31       0
Internet Mail Gateway         Started        14:13:32       0
Local Client Interface        Enabled        14:13:32       0
Remote Client Interface       Enabled        14:13:32       0
Test Server                   Started        14:13:32       0
Request Server                Started        14:13:32       0
Print Server                  Started        14:13:32       0
Bulletin Board Server         Started        14:13:32       0
Background Search Service     Started        14:13:32       0
CDA Server                    Started        14:13:32       0
POP3 interface                Started        14:13:32       0
Omscan Server                 Started        14:13:32       0
Archiver                      Started        14:13:32       0


regards
michael

[MikeyMZ]

I also removed the imap-cache for that user and also for all other users with no effect.

[ScalixSupport]

Michael!

Ideal steps to run omscan, perform the steps below to try and reslove the issue:

Code: Select all

omoff -d0 omscan 
omscan -Z     
omon omscan     

You need to watch the status of the omscan process using the command:

Code: Select all

omscan -t

Wait until you get a message that says "Current server cycle not started; service reset or
delayed".

Now try to fix the mailstore related issues in active mode using the below given command:

Code: Select all

omscan -Avfx -U <username>

Thanks,
Subir

[MikeyMZ]

Thanks for responding ... But same effect as before

Here is the output:

Code: Select all

medix:~ # omoff -d0 omscan
Disabling 1 subsystem(s).
medix:~ # omscan -Z
Resetting server cycle .... done.
medix:~ # omon omscan
Enabling 1 subsystem(s).
medix:~ # omscan -t
Last omscan tool run on 03.19.07 at 14:00:13; duration 1 minute(s).
Previous server cycle run on 01.01.70 at 01:00:00; duration 0 minute(s).
Current server cycle started on 03.19.07 at 15:00:52; in progress.
medix:~ # omscan -t
Last omscan tool run on 03.19.07 at 14:00:13; duration 1 minute(s).
Previous server cycle run on 01.01.70 at 01:00:00; duration 0 minute(s).
Current server cycle started on 03.19.07 at 15:00:52; in progress.
medix:~ # omscan -t
Last omscan tool run on 03.19.07 at 14:00:13; duration 1 minute(s).
Previous server cycle run on 01.01.70 at 01:00:00; duration 0 minute(s).
Current server cycle started on 03.19.07 at 15:00:52; in progress.
medix:~ # omscan -t
Last omscan tool run on 03.19.07 at 14:00:13; duration 1 minute(s).
Previous server cycle run on 01.01.70 at 01:00:00; duration 0 minute(s).
Current server cycle started on 03.19.07 at 15:00:52; in progress.
medix:~ # omscan -t
Last omscan tool run on 03.19.07 at 14:00:13; duration 1 minute(s).
Previous server cycle run on 03.19.07 at 15:00:52; duration 2 minute(s).
Current server cycle not started; service reset or delayed.

medix:~ # omscan -Avfx -U "Michael Maag/medix"
omscan running on 03.19.07 at 15:03:48.
Host computer : medix.mami.mine.nu.
Fix mode requested.

Last omscan tool run on 03.19.07 at 14:00:13; duration 1 minute(s).
Previous server cycle run on 03.19.07 at 15:00:52; duration 2 minute(s).
Current server cycle not started; service reset or delayed.


Extra check option requested.
Active scan option requested.

Scanning file/dir links .... done.

CAUTION: Scanning of message store has started.
         Mounted file/dir links must be maintained during the scan.
         VxFS file system must not be reorganized - see omscan(1M).

Checking/Scanning user trays ....Michael Maag / medix/CN=Michael Maag
 done.

Disk usage ....

USER NAME                          IN    OUT    PDG   FCAB   DLST     WB   TOTAL (KB)

Michael Maag /medix/CN=Michael 106033      1    212    199      1     26 106472


thanks
michael

[jbertoldi]

Started Friday night

SERIOUS ERROR          SMTP Relay   (SMTPD Relay Pr) 03.19.07 08:18:53
[OM 10270] Process about to terminate due to error.
Signal (Segmentation Violation) trapped by process 31737
Procedure trace follows:
 <- inet_ParseArpaAddress
 -> nm_ParseORN
 <- nm_ParseORN
 -> nm_PutFieldStr
 -> nm_PutFieldMem
 -> nm_AppendFieldMem
 -> nm_AddSeparators
 <- nm_AddSeparators
 -> nm_ParseORN
 <- nm_ParseORN
 <- nm_AppendFieldMem
 <- nm_PutFieldMem
 <- nm_PutFieldStr
 <- inet_ConvArpaORNToORN
 -> mim_CloseMapDir
 <- mim_CloseMapDir
SERIOUS ERROR          SMTP Relay   (SMTPD Relay Pr) 03.19.07 08:18:53
[OM 10272] BACKTRACE:
/opt/scalix/lib/libom_er.so(er_add_backtrace+0xc6)[0x652f06]
/opt/scalix/lib/libom_er.so[0x6531d6]
/opt/scalix/lib/libom_er.so(er_DumpProcAndExit+0x1f)[0x65337f]
/lib/tls/libpthread.so.0[0x11c898]
/opt/scalix/lib/libom_mim.so(mim_catchUser+0xf3)[0xd5c1c3]
/opt/scalix/bin/ommap

[KevinAnderson]

Can you please post /var/opt/scalix/??/s/logs/fatal?

Kev.

[MikeyMZ]

Now I tested the Outlook-Access. I was able to see and delete Messages within OL but it seems there is no synchronization. On server i see heavy access.

The OL-Logfile output:

Code: Select all

18:38:45  ================================================================
18:38:45  Starte Synchronisierung: FullSync: Vollstndige, lokale->Remote-Sync.,
18:38:45  bertrage, FB-Update
18:38:45  ================================================================
18:38:45  Initialisiere
18:38:45  Synchronisieren der(des) folgenden Ordner(s):
18:38:45     Mailbox - lollo     
....
....
....
18:38:45  Synchronisieren der Ordner-Hierarchie
18:38:45     Suchen nach Offline-Änderungen
18:38:45     Keine Änderungen gefunden


This is eveery 2 Seconds.

the output of the fatal-log is:

Code: Select all

SERIOUS ERROR           Remote Client (U/I Access    ) Mon Mar 19 18:35:56 2007
[OM 10270] Process about to terminate due to error.
Signal (Segmentation Violation) trapped by process 24049
Procedure trace follows:
  -> im_OpenItem
  -> im_ItemRef2FName
  <- im_ItemRef2FName
  <- im_OpenItem
  <- sfl_OpenSfl
  <- sfl_OpenItem
  <- im_OpenItem
  -> ct_FindDITEntry
  <- ct_FindDITEntry
  -> ct_MapDITEntryToRef
  <- ct_MapDITEntryToRef
  -> ct_MatchCounts
  <- ct_MatchCounts
  -> ct_ClearRecCounts
  <- ct_ClearRecCounts
  <- ct_OpenCtner 3006
User Name: Michael Maag / medix/CN=Michael Maag
Pid of logging process: 24049
  Last Msg Subject: status report from ddclient@medix
  Last Msg Sender: root////internet///////////RFC-822/root@mami.mine.nu///////%%%%//root <
  Last Msg Id: E1HT7XA-00082J-2w(a)medix.mami.mine.nu
  Last Ct RecNo: 1


SERIOUS ERROR           Remote Client (U/I Access    ) Mon Mar 19 18:35:56 2007
[OM 10272] BACKTRACE:
/opt/scalix/lib/libom_er.so(er_add_backtrace+0xb3)[0xb7f36d43]
/opt/scalix/lib/libom_er.so[0xb7f3702c]
/opt/scalix/lib/libom_er.so(er_DumpProcAndExit+0x1f)[0xb7f371bf]
[0xffffe420]
/opt/scalix/lib/libom_ct.so(ct_DetachCtner+0x215)[0xb7ac5fcd]
/opt/scalix/lib/libom_ual.so(ual_DeleteRecord+0x283)[0xb7e07475]
/opt/scalix/lib/libom_ual.so(ual_DeleteItem+0xa53)[0xb7e3c467]
/opt/scalix/lib/libom_ual.so[0xb7eb14b2]
/opt/scalix/lib/libom_ual.so[0xb7eb21c2]
/opt/scalix/lib/libom_ual.so(ual_PutFolderSync+0x1c3)[0xb7eb2ad7]
/opt/scalix/lib/libom_ual.so(ual_RecvReply+0xf0e)[0xb7e73f03]
/opt/scalix/lib/libom_ual.so(ual_ProcessCommands+0xe3)[0xb7e8062b]
/opt/scalix/bin/ual.remote[0x804e8cf]
/lib/libc.so.6(__libc_start_main+0xdc)[0xb7cba87c]
/opt/scalix/bin/ual.remote[0x8049a21]
User Name: Michael Maag / medix/CN=Michael Maag
Pid of logging process: 24049
  Last Msg Subject: status report from ddclient@medix
  Last Msg Sender: root////internet///////////RFC-822/root@mami.mine.nu///////%%%%//root <
  Last Msg Id: E1HT7XA-00082J-2w(a)medix.mami.mine.nu
  Last Ct RecNo: 1


Michael

[ScalixSupport]

Hi Michael!

We have an open bug for "SERIOUS ERROR Remote Client (U/I Access)" issue:
http://bugzilla.scalix.com/show_bug.cgi?id=14925

We are trying to resolve the same.

Thanks,
Subir

[gren]

I think there is some new information in the fatal log fragment you which refers to a segmentation violation in ct_DetachCtner+0x215,
so I have added a new bug :

http://bugzilla.scalix.com/show_bug.cgi?id=14997

Regards,
Gren.