Re: [SOGo] strange log entries
thanks for the updates! Marcus users@sogo.nu (mj), 2018.11.10 (Sat) 12:20 (CET): > A last update: > > Inverse has changed this situation is logged to a more meaningful message. > See this commit: > > https://github.com/inverse-inc/sogo/commit/8734ee74861f8ec0498d78a1a39c3d1f1718df4d > > MJ > > On 11/9/18 5:47 PM, mj (li...@merit.unu.edu) wrote: > > An update on this, for the archives. > > > > SOGo support is telling me: > > > > > If the IP addresses are legit, it them means their session has expired. > > > > > > So the entires in both memcached/the database for the user session > > > are gone, while the user tries to use it again. > > > > > > There's nothing to worry about, it just means the user was brought > > > back to the login script of SOGo. -- users@sogo.nu https://inverse.ca/sogo/lists
Re: [SOGo] strange log entries
A last update: Inverse has changed this situation is logged to a more meaningful message. See this commit: https://github.com/inverse-inc/sogo/commit/8734ee74861f8ec0498d78a1a39c3d1f1718df4d MJ On 11/9/18 5:47 PM, mj (li...@merit.unu.edu) wrote: An update on this, for the archives. SOGo support is telling me: If the IP addresses are legit, it them means their session has expired. So the entires in both memcached/the database for the user session are gone, while the user tries to use it again. There's nothing to worry about, it just means the user was brought back to the login script of SOGo. -- users@sogo.nu https://inverse.ca/sogo/lists
Re: [SOGo] strange log entries
An update on this, for the archives. SOGo support is telling me: If the IP addresses are legit, it them means their session has expired. So the entires in both memcached/the database for the user session are gone, while the user tries to use it again. There's nothing to worry about, it just means the user was brought back to the login script of SOGo. -- users@sogo.nu https://inverse.ca/sogo/lists
Re: [SOGo] strange log entries
Hi Christian, Thanks. On 5-11-2018 10:34, Christian Mack (christian.m...@uni-konstanz.de) wrote: We still see those entries and had never problems with them. I guess you are also using something (like apache) in front of sogo. Have you also checked the apache logs, to see if you can find a corresponding connection attempt there, with perhaps a remote IP or so? Strange enough, we can't seem to find corresponding log-lines in apache logs at the time of the SOGoWebAuthenticator wrong passwords in sogo.log. MJ -- users@sogo.nu https://inverse.ca/sogo/lists
Re: [SOGo] strange log entries
Hi We do not use SAML for SOGo. We do use Shibboleth for our Website though. But I do not think that is related. We still see those entries and had never problems with them. Kind regards, Christian Mack Am 02.11.18 um 19:17 schrieb mj (li...@merit.unu.edu): > Hi Christian, > > Thanks for taking the time to repy. Inverse is suggesting that they > might perhaps be timed-out SAML sessions. (we have been trying sogo with > SAML auth in a test setup) > > Are you by any chance also using saml auth? (or have you been using it?) > > Reassuring that you see them as well, though. > > Again: thanks. > > MJ > > On 11/2/18 4:50 PM, Christian Mack (christian.m...@uni-konstanz.de) wrote: >> Hi >> >> We also get those several dozen times a day. >> They are normal. >> A friend of mine hinted, that these are access checks from the great >> chinese firewall. >> >> >> Kind regards, >> Christian Mack >> -- Christian Mack Universität Konstanz Kommunikations-, Informations-, Medienzentrum (KIM) Abteilung Basisdienste 78457 Konstanz +49 7531 88-4416 smime.p7s Description: S/MIME Cryptographic Signature
Re: [SOGo] strange log entries
Hi Christian, Thanks for taking the time to repy. Inverse is suggesting that they might perhaps be timed-out SAML sessions. (we have been trying sogo with SAML auth in a test setup) Are you by any chance also using saml auth? (or have you been using it?) Reassuring that you see them as well, though. Again: thanks. MJ On 11/2/18 4:50 PM, Christian Mack (christian.m...@uni-konstanz.de) wrote: Hi We also get those several dozen times a day. They are normal. A friend of mine hinted, that these are access checks from the great chinese firewall. Kind regards, Christian Mack -- users@sogo.nu https://inverse.ca/sogo/lists
Re: [SOGo] strange log entries
Hi We also get those several dozen times a day. They are normal. A friend of mine hinted, that these are access checks from the great chinese firewall. Kind regards, Christian Mack Am 01.11.18 um 13:43 schrieb mj (li...@merit.unu.edu): > Hi Marcus, > > Thanks very much for your reply. We have apache in front of sogo, and as > fas as I can see, apache is logging nothing special at the time of these > authentication attempts. > > We had 5 of these auth attempts this morning at 06:01. Here are some > more (probably too many) logs from sogo, and further down the same same > period apache logs. > > Hopefully someone here can spot something that I am missing. > > Sogo this morning: >> Nov 01 06:01:35 sogod [26091]: |SOGo| starting method 'POST' on uri >> '/SOGo/Microsoft-Server-ActiveSync?Cmd=Sync=user_av=C1EFA48B85=SAMSUNGSMT805' >> >> Nov 01 06:01:37 sogod [25952]: [WARN] >> <0x0x55e5d00d6ff0[WOWatchDogChild]> pid 25975 has been hanging in the >> same request for 3 minutes >> Nov 01 06:01:38 sogod [26098]: >> <0x0x55e5d9a5b710[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while >> detecting changes for user user_heu in Ping... >> Nov 01 06:01:38 sogod [26058]: |SOGo| starting method 'POST' on uri >> '/SOGo/Microsoft-Server-ActiveSync?Cmd=Ping=user_ta=androidc1214775124=Android' >> >> Nov 01 06:01:38 sogod [25975]: >> <0x0x55e5d6bc06f0[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while >> detecting changes for user user_bie in Ping... >> Nov 01 06:01:40 sogod [26091]: |SOGo| request took 4.681785 seconds to >> execute >> Nov 01 06:01:40 sogod [26091]: 198.54.173.196 "POST >> /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync=user_av=SEC16FB85=SAMSUNGSMT805 >> HTTP/1.1" 503 0/144 4.683 - - 0 >> Nov 01 06:01:40 sogod [25978]: |SOGo| request took 36.488380 seconds >> to execute >> Nov 01 06:01:40 sogod [25978]: 198.54.173.196 "POST >> /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync=user_av=SEC16F5=SAMSUNGSMT805 >> HTTP/1.1" 200 0/144 36.489 - - 0 >> Nov 01 06:01:40 sogod [25992]: |SOGo| request took 24.210513 seconds >> to execute >> Nov 01 06:01:40 sogod [25992]: 198.54.173.196 "POST >> /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync=user_av=SEC1EFA48B85=SAMSUNGSMT805 >> HTTP/1.1" 503 0/144 24.212 - - 0 >> Nov 01 06:01:40 sogod [26065]: >> <0x0x55e5d6bc43a0[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while >> detecting changes for user user_pi in Ping... >> Nov 01 06:01:40 sogod [26058]: >> <0x0x55e5d93c02a0[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while >> detecting changes for user user_ta in Ping... >> Nov 01 06:01:40 sogod [25974]: >> <0x0x55e5d4680b20[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while >> detecting changes for user user_sa in Ping... >> Nov 01 06:01:41 sogod [25990]: >> <0x0x55e5d3da6ed0[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while >> detecting changes for user user_vi in Ping... >> Nov 01 06:01:41 sogod [25980]: >> <0x0x55e5d278e3d0[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while >> detecting changes for user user_sa in Ping... >> Nov 01 06:01:42 sogod [25992]: |SOGo| starting method 'POST' on uri >> '/SOGo/Microsoft-Server-ActiveSync?Cmd=Sync=user_av=S6FC1EFA48B85=SAMSUNGSMT805' >> >> Nov 01 06:01:42 sogod [25992]: |SOGo| request took 0.417357 seconds to >> execute >> Nov 01 06:01:42 sogod [25992]: 198.54.173.196 "POST >> /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync=user_av=SEC16FC1EB85=SAMSUNGSMT805 >> HTTP/1.1" 200 0/144 0.419 - - 0 >> Nov 01 06:01:43 sogod [25984]: >> <0x0x55e5d919e0b0[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while >> detecting changes for user user_fo in Ping... >> Nov 01 06:01:44 sogod [25979]: >> <0x0x55e5d84d9e50[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while >> detecting changes for user user_to in Ping... >> Nov 01 06:01:45 sogod [25952]: [WARN] >> <0x0x55e5d017b990[WOWatchDogChild]> pid 26071 has been hanging in the >> same request for 3 minutes >> Nov 01 06:01:45 sogod [25981]: |SOGo| request took 332.461077 seconds >> to execute >> Nov 01 06:01:45 sogod [25981]: [ERROR] >> <0x0x55e5d4e0f3e0[WOHttpTransaction]> client disconnected during >> delivery of response for > uri=/SOGo/Microsoft-Server-ActiveSync?User=user_sa%40merit.unu.edu=7B687EA44DD55=Outlook=Ping >> app=SOGo rqKey=Microsoft-Server-ActiveSync rqPath=(null)> (len=13): >> the socket was shutd >> Nov 01 06:01:45 sogod [25981]: 52.125.140.40 "POST >> /SOGo/Microsoft-Server-ActiveSync?User=user_sa%40merit.unu.edu=7C3DEA44DD55=Outlook=Ping >> HTTP/1.1" 200 13/246 332.463 - - 0 >> Nov 01 06:01:46 sogod [26071]: >> <0x0x55e5d7556c00[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while >> detecting changes for user user_kro in Ping... >> Nov 01 06:01:46 sogod [26075]: >> <0x0x55e5d65ae130[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while >> detecting changes for user user_sa in Ping... >> Nov 01 06:01:46 sogod [25981]: |SOGo| starting method 'POST' on uri >> '/SOGo/Microsoft-Server-ActiveSync?Cmd=FolderSync=user_av=SEC16FC48B85=SAMSUNGSMT805' >> >> Nov 01 06:01:46 sogod [26084]:
Re: [SOGo] strange log entries
Hi Marcus, Thanks very much for your reply. We have apache in front of sogo, and as fas as I can see, apache is logging nothing special at the time of these authentication attempts. We had 5 of these auth attempts this morning at 06:01. Here are some more (probably too many) logs from sogo, and further down the same same period apache logs. Hopefully someone here can spot something that I am missing. Sogo this morning: Nov 01 06:01:35 sogod [26091]: |SOGo| starting method 'POST' on uri '/SOGo/Microsoft-Server-ActiveSync?Cmd=Sync=user_av=C1EFA48B85=SAMSUNGSMT805' Nov 01 06:01:37 sogod [25952]: [WARN] <0x0x55e5d00d6ff0[WOWatchDogChild]> pid 25975 has been hanging in the same request for 3 minutes Nov 01 06:01:38 sogod [26098]: <0x0x55e5d9a5b710[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user user_heu in Ping... Nov 01 06:01:38 sogod [26058]: |SOGo| starting method 'POST' on uri '/SOGo/Microsoft-Server-ActiveSync?Cmd=Ping=user_ta=androidc1214775124=Android' Nov 01 06:01:38 sogod [25975]: <0x0x55e5d6bc06f0[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user user_bie in Ping... Nov 01 06:01:40 sogod [26091]: |SOGo| request took 4.681785 seconds to execute Nov 01 06:01:40 sogod [26091]: 198.54.173.196 "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync=user_av=SEC16FB85=SAMSUNGSMT805 HTTP/1.1" 503 0/144 4.683 - - 0 Nov 01 06:01:40 sogod [25978]: |SOGo| request took 36.488380 seconds to execute Nov 01 06:01:40 sogod [25978]: 198.54.173.196 "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync=user_av=SEC16F5=SAMSUNGSMT805 HTTP/1.1" 200 0/144 36.489 - - 0 Nov 01 06:01:40 sogod [25992]: |SOGo| request took 24.210513 seconds to execute Nov 01 06:01:40 sogod [25992]: 198.54.173.196 "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync=user_av=SEC1EFA48B85=SAMSUNGSMT805 HTTP/1.1" 503 0/144 24.212 - - 0 Nov 01 06:01:40 sogod [26065]: <0x0x55e5d6bc43a0[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user user_pi in Ping... Nov 01 06:01:40 sogod [26058]: <0x0x55e5d93c02a0[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user user_ta in Ping... Nov 01 06:01:40 sogod [25974]: <0x0x55e5d4680b20[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user user_sa in Ping... Nov 01 06:01:41 sogod [25990]: <0x0x55e5d3da6ed0[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user user_vi in Ping... Nov 01 06:01:41 sogod [25980]: <0x0x55e5d278e3d0[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user user_sa in Ping... Nov 01 06:01:42 sogod [25992]: |SOGo| starting method 'POST' on uri '/SOGo/Microsoft-Server-ActiveSync?Cmd=Sync=user_av=S6FC1EFA48B85=SAMSUNGSMT805' Nov 01 06:01:42 sogod [25992]: |SOGo| request took 0.417357 seconds to execute Nov 01 06:01:42 sogod [25992]: 198.54.173.196 "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync=user_av=SEC16FC1EB85=SAMSUNGSMT805 HTTP/1.1" 200 0/144 0.419 - - 0 Nov 01 06:01:43 sogod [25984]: <0x0x55e5d919e0b0[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user user_fo in Ping... Nov 01 06:01:44 sogod [25979]: <0x0x55e5d84d9e50[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user user_to in Ping... Nov 01 06:01:45 sogod [25952]: [WARN] <0x0x55e5d017b990[WOWatchDogChild]> pid 26071 has been hanging in the same request for 3 minutes Nov 01 06:01:45 sogod [25981]: |SOGo| request took 332.461077 seconds to execute Nov 01 06:01:45 sogod [25981]: [ERROR] <0x0x55e5d4e0f3e0[WOHttpTransaction]> client disconnected during delivery of response for (len=13): the socket was shutd Nov 01 06:01:45 sogod [25981]: 52.125.140.40 "POST /SOGo/Microsoft-Server-ActiveSync?User=user_sa%40merit.unu.edu=7C3DEA44DD55=Outlook=Ping HTTP/1.1" 200 13/246 332.463 - - 0 Nov 01 06:01:46 sogod [26071]: <0x0x55e5d7556c00[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user user_kro in Ping... Nov 01 06:01:46 sogod [26075]: <0x0x55e5d65ae130[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user user_sa in Ping... Nov 01 06:01:46 sogod [25981]: |SOGo| starting method 'POST' on uri '/SOGo/Microsoft-Server-ActiveSync?Cmd=FolderSync=user_av=SEC16FC48B85=SAMSUNGSMT805' Nov 01 06:01:46 sogod [26084]: <0x0x55e5d8f67c60[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user user_pa in Ping... 2018-11-01 06:01:47.380 sogod[25981] ERROR(-[NGLdapSearchResultEnumerator nextObject]): does not support result references yet .. 2018-11-01 06:01:47.535 sogod[25981] ERROR(-[NGLdapSearchResultEnumerator nextObject]): does not support result references yet .. 2018-11-01 06:01:47.699 sogod[25981] ERROR(-[NGLdapSearchResultEnumerator nextObject]): does not support result references yet .. 2018-11-01 06:01:47.854 sogod[25981] ERROR(-[NGLdapSearchResultEnumerator nextObject]): does not support result
Re: [SOGo] strange log entries
users@sogo.nu (mj), 2018.10.31 (Wed) 15:16 (CET): > We have noticed lines like the following in our sogo logs: > > Wed Oct 31 12:33:06 CET 2018 Oct 31 12:33:06 sogod [25987]: > > <0x0x55e5d005b120[SOGoWebAuthenticator]> tried wrong password for > > user > > '+xIpPJifKpSoK0Yez1t6b3G/5wmx7uWGx7RbDKRof+7gcXgU4vK1++l/NG4YGKZNbryHUf9cNdsKPahmogY6cD1O37hK9klMQe9T8vJ9H860n7vq+p3yIgQu01pSp+N6WyxGxu1pCtTu6dWk85wRT/fOZWTi+bE339XmGQZUsKOmKRzWVCjQ4nsZ+Mr0GfSAFCSWJy6EeCYujPcEyC42cQ=='! > > SOGo works beautifully, but we wonder what hese log lines mean. The username > is obviously so strange, that it is very unlikely someone mistyping his/her > username. Maybe you are being fuzzed by some web vulnerability scanner... At first sight I thought it might be base64 encoded, but decoding it gives just utf8 garbage. The two "==" at the end look like the end of all of my ssh keys. > Does anyone recognise this as something SOGo-internal, perhaps..? No! > We are using SOGo for regular (email/calendar) web access, plus ActiveSync > and some carddav/caldav. Unfortunately, no IP is logged with the lines. > (they appear at irregular times/frequencies) You are running sogo behind a reverse proxy, go for the log files of this daemon and correlate to get the IP! Marcus -- users@sogo.nu https://inverse.ca/sogo/lists
[SOGo] strange log entries
Hi, We have noticed lines like the following in our sogo logs: Wed Oct 31 12:22:22 CET 2018 Oct 31 12:22:22 sogod [25985]: <0x0x55e5d01df1a0[SOGoWebAuthenticator]> tried wrong password for user 'XBlOMdQZDvM5f86H7iBtmUiCFCxPrvGxVW25E3BHqzga7DU7Kh62fRJ/8hRQ/lwJvJlnygErqla35o8qv3DADhZ85cVGzJIXy+JXqckSn+IZsHlKIf5Tv47Ed5f6JOG+dQby0wd3zUJoWskxpvyPzwNIbKvg9l5BDGGMQlojzPHIvcerv82XEx2RWbRknvqxWYVH+ScREBMvvOGO0PzbOA=='! Wed Oct 31 12:29:40 CET 2018 Oct 31 12:29:40 sogod [26053]: <0x0x55e5cfe82c40[SOGoWebAuthenticator]> tried wrong password for user '+AxMdDC6NgthqY1iIgxWEp8C0fjzXtRVHzN175GP/C0AW6r5d3K5hpSdICSYPoEOgnGWv78AvSU5VmmVx3B39BMKkwBmtFnjd66o0+U1A5mJqs82d0KQU8Qqo/mZ410QJkDbel8BEjs24g98lGAffOdFATpeUkawOK52s9vymkdZGThKwjqMtY36Z0j3P0407x3aEfja+LeMSaFwpexT6w=='! Wed Oct 31 12:33:06 CET 2018 Oct 31 12:33:06 sogod [25987]: <0x0x55e5d005b120[SOGoWebAuthenticator]> tried wrong password for user '+xIpPJifKpSoK0Yez1t6b3G/5wmx7uWGx7RbDKRof+7gcXgU4vK1++l/NG4YGKZNbryHUf9cNdsKPahmogY6cD1O37hK9klMQe9T8vJ9H860n7vq+p3yIgQu01pSp+N6WyxGxu1pCtTu6dWk85wRT/fOZWTi+bE339XmGQZUsKOmKRzWVCjQ4nsZ+Mr0GfSAFCSWJy6EeCYujPcEyC42cQ=='! SOGo works beautifully, but we wonder what hese log lines mean. The username is obviously so strange, that it is very unlikely someone mistyping his/her username. Does anyone recognise this as something SOGo-internal, perhaps..? We are using SOGo for regular (email/calendar) web access, plus ActiveSync and some carddav/caldav. Unfortunately, no IP is logged with the lines. (they appear at irregular times/frequencies) Ideas? MJ -- users@sogo.nu https://inverse.ca/sogo/lists
