search

the-djmaze / snappymail

Simple, modern & fast web-based email client
https://snappymail.eu
GNU Affero General Public License v3.0
1.01k stars 121 forks source link

Can not login into admin panel on new installation #354

Closed Euphonique closed 2 years ago

Euphonique commented 2 years ago

Installed the latest release of snappymail (v2.15.0, php 7.4) and can not login to admin panel with the provided password from password file. "Authentication failed" No log entries, tried different browsers, reset config, cache... Rainloop works. Any ideas?

the-djmaze commented 2 years ago

Are you using Nginx just like #340 ?

Rainloop works

Probably, it is not as secure as SnappyMail, so probably security is triggered.

Also read: https://github.com/the-djmaze/snappymail/wiki/FAQ#how-do-i-enable-logging

Euphonique commented 2 years ago

Are you using Nginx just like #340 ?

Rainloop works

Probably, it is not as secure as SnappyMail, so probably security is triggered.

Also read: https://github.com/the-djmaze/snappymail/wiki/FAQ#how-do-i-enable-logging

No, it runs Apache 2.4 and rainloop is installed on another subdomain/different folder. And it doesn‘t load the page like in #340 either. Only the „Authentication failed“ message above the login form.

the-djmaze commented 2 years ago

Then enable logging. https://github.com/the-djmaze/snappymail/wiki/FAQ#how-do-i-enable-logging

Euphonique commented 2 years ago

Then enable logging. https://github.com/the-djmaze/snappymail/wiki/FAQ#how-do-i-enable-logging

Logging is enabled but there is no log-file. :(

Javascript Console: Uncaught (in promise) Error: The message port closed before a response was received. And the message in the form:

error

the-djmaze commented 2 years ago

Javascript Console: Uncaught (in promise) Error: The message port closed before a response was received.

I need the trace! Filename and line number where the error occurred.

Potusek commented 2 years ago

New installation :/ `[2022-05-03 20:32:02.061][82e44a3a] JSON[NOTE]: Action: DoAdminLogin

[2022-05-03 20:32:03.050][82e44a3a] INFO[NOTICE]: RainLoop\Exceptions\ClientException: AuthError[102] in /var/www/html/snappymail/snappymail/v/2.15.1/app/libraries/RainLoop/ActionsAdmin.php:137 Stack trace:

0 /var/www/html/snappymail/snappymail/v/2.15.1/app/libraries/RainLoop/ServiceActions.php(155): RainLoop\ActionsAdmin->DoAdminLogin()

1 /var/www/html/snappymail/snappymail/v/2.15.1/app/libraries/RainLoop/Service.php(133): RainLoop\ServiceActions->ServiceJson()

2 /var/www/html/snappymail/snappymail/v/2.15.1/app/libraries/RainLoop/Service.php(15): RainLoop\Service::RunResult()

3 /var/www/html/snappymail/snappymail/v/2.15.1/include.php(169): RainLoop\Service::Handle()

4 /var/www/html/snappymail/index.php(11): include('...')

5 {main}`

Euphonique commented 2 years ago

Javascript Console: Uncaught (in promise) Error: The message port closed before a response was received.

I need the trace! Filename and line number where the error occurred.

Sorry, the error wasn't from snappymail.

But after some investigation I think I understand what happens: I edit the config and switched the log on, but after reloading the login page the config got overwritten to the defaults. Thats why there are no logfiles. The same happens with the admin password file: Everytime I reload the login page, there is a new admin password in the file. I guess the login fails, because snappymail generates a new password everytime the page loads. It seems it generates the whole data folder in its default state again and again. The question is: Why???

I use froxlor as the server admin panel. And the folders are not in /var/www/ but in /var/customers/webs/CUSTOMERNAME/ Also the username is not www-data but the username for the respective webspace. If I install snappymail in /var/www/ it works as expected. But thats not a solution for me. Maybe it has something to do with the OpenBaseDir or fastcgi?

Euphonique commented 2 years ago

I've changed the default settings in Application.ini to 'enable' => array(true, 'Enable logging'), and voila: A Logfile! But no new information here I guess.. But it confirms my suspicion, that snappymail overwrites the existing config with the default one. But why?

[2022-05-05 11:35:56.590][4b225f4c] INFO[DATA]: [DATE:2022-05-05 UTC][SM:2.15.1][IP:93.204.167.198][PID:464004][Apache/2.4.41 (Ubuntu)][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3] [2022-05-05 11:35:56.590][4b225f4c] REQUEST[NOTE]: [GET] https://webmail.pagel.email/?admin

[2022-05-05 11:35:56.591][4b225f4c] INFO[DATA]: [DATE:2022-05-05 UTC][SM:2.15.1][IP:93.204.167.198][PID:464004][Apache/2.4.41 (Ubuntu)][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3] [2022-05-05 11:35:56.591][4b225f4c] REQUEST[NOTE]: [GET] https://webmail.pagel.email/?admin [2022-05-05 11:35:56.607][4b225f4c] INFO[MEMORY]: Memory peak usage: 2MB [2022-05-05 11:35:56.608][4b225f4c] INFO[TIME]: Time delta: 0.047916889190674

[2022-05-05 11:35:56.686][77655836] INFO[DATA]: [DATE:2022-05-05 UTC][SM:2.15.1][IP:93.204.167.198][PID:464003][Apache/2.4.41 (Ubuntu)][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3] [2022-05-05 11:35:56.686][77655836] REQUEST[NOTE]: [GET] https://webmail.pagel.email/?/AdminAppData/0/7395077965438916/ [2022-05-05 11:35:56.783][77655836] APPDATA[DATA]: rl.initData({"Auth":false,"AccountHash":"","AccountSignMe":false,"MailToEmail":"","Email":"","DevEmail":"","DevPassword":"","Title":"SnappyMail Webmail","LoadingDescription":"SnappyMail","FaviconUrl":"","LoginDefaultDomain":"","hideSubmitButton":true,"DetermineUserLanguage":true,"DetermineUserDomain":false,"SieveAllowFileintoInbox":false,"ContactsIsAllowed":false,"Admin":[],"Capa":[],"Plugins":[],"System":{"version":"2.15.1","admin":true,"webPath":"\/","webVersionPath":"\/snappymail\/v\/2.15.1\/","token":"ae752cd91ebc39da97adfc3a624392ba9bb27ec2","inIframe":false,"allowHtmlEditorBitiButtons":false,"allowCtrlEnterOnCompose":true,"useImapThread":true,"allowAppendMessage":false,"folderSpecLimit":50,"listPermanentFiltered":false,"themes":["Default","A","Blurred","DarkShine","Linen","Love","Snow","SnowDarkV1","Squares","SquaresDark","Stripes","Wood","Xv","Clear"],"languages":["ar-SA","bg-BG","cs-CZ","da-DK","de-DE","el-GR","en","en-US","es-ES","et-EE","fa-IR","fi-FI","fr-FR","hu-HU","id-ID","is-IS","it-IT","ja-JP","ko-KR","lt-LT","lv-LV","nb-NO","nl-NL","pl-PL","pt-BR","pt-PT","ro-RO","ru-RU","sk-SK","sl-SI","sv-SE","tr-TR","uk-UA","zh-CN","zh-TW"],"languagesAdmin":["cs-CZ","da-DK","de-DE","en","es-ES","fa-IR","fi-FI","fr-FR","hu-HU","id-ID","it-IT","ja-JP","lt-LT","nb-NO","nl-NL","pl-PL","pt-BR","ru-RU","sk-SK","sl-SI","sv-SE","zh-CN"],"attachmentsActions":["zip"],"adminHostUse":false,"adminPath":"admin","adminAllowed":true},"NewMoveToFolder":true,"AllowLanguagesOnSettings":true,"AllowLanguagesOnLogin":true,"AttachmentLimit":26214400,"SignMe":"DefaultOff","UseLocalProxyForExternalImages":true,"ViewHTML":true,"ShowImages":false,"RemoveColors":false,"MessagesPerPage":20,"MessageReadDelay":5,"SoundNotification":true,"NotificationSound":"new-mail","DesktopNotifications":true,"Layout":1,"EditorDefaultType":"Html","UseCheckboxesInList":true,"AutoLogout":30,"UseThreads":false,"AllowDraftAutosave":true,"ReplySameFolder":false,"ContactsAutosave":true,"HideUnsubscribed":false,"MainEmail":"","InterfaceAnimation":true,"UserBackgroundName":"","UserBackgroundHash":"","LanguageAdmin":"en","UserLanguageAdmin":"de-DE","Theme":"Default","Language":"en","UserLanguage":"de-DE","PluginsLink":"","StaticLibsJs":"\/snappymail\/v\/2.15.1\/static\/js\/min\/libs.min.js"}); [2022-05-05 11:35:56.785][77655836] INFO[MEMORY]: Memory peak usage: 2MB [2022-05-05 11:35:56.785][77655836] INFO[TIME]: Time delta: 0.12656283378601

[2022-05-05 11:36:09.374][00938470] INFO[DATA]: [DATE:2022-05-05 UTC][SM:2.15.1][IP:93.204.167.198][PID:464004][Apache/2.4.41 (Ubuntu)][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3] [2022-05-05 11:36:09.375][00938470] REQUEST[NOTE]: [POST] https://webmail.pagel.email/?admin/Json/&q[]=/0/

[2022-05-05 11:36:09.375][00938470] INFO[DATA]: [DATE:2022-05-05 UTC][SM:2.15.1][IP:93.204.167.198][PID:464004][Apache/2.4.41 (Ubuntu)][fpm-fcgi][Streams:tcp,udp,unix,udg,ssl,tls,tlsv1.0,tlsv1.1,tlsv1.2,tlsv1.3] [2022-05-05 11:36:09.376][00938470] REQUEST[NOTE]: [POST] https://webmail.pagel.email/?admin/Json/&q[]=/0/ [2022-05-05 11:36:09.376][00938470] JSON[NOTE]: Action: DoAdminLogin

[2022-05-05 11:36:10.346][00938470] INFO[NOTICE]: RainLoop\Exceptions\ClientException: AuthError[102] in /var/customers/webs/pagel/webmail/snappymail/v/2.15.1/app/libraries/RainLoop/ActionsAdmin.php:137 Stack trace:

0 /var/customers/webs/pagel/webmail/snappymail/v/2.15.1/app/libraries/RainLoop/ServiceActions.php(155): RainLoop\ActionsAdmin->DoAdminLogin()

1 /var/customers/webs/pagel/webmail/snappymail/v/2.15.1/app/libraries/RainLoop/Service.php(133): RainLoop\ServiceActions->ServiceJson()

2 /var/customers/webs/pagel/webmail/snappymail/v/2.15.1/app/libraries/RainLoop/Service.php(15): RainLoop\Service::RunResult()

3 /var/customers/webs/pagel/webmail/snappymail/v/2.15.1/include.php(170): RainLoop\Service::Handle()

4 /var/customers/webs/pagel/webmail/index.php(11): include('/var/customers/...')

5 {main}

[2022-05-05 11:36:10.349][00938470] INFO[MEMORY]: Memory peak usage: 2MB [2022-05-05 11:36:10.349][00938470] INFO[TIME]: Time delta: 1.0033640861511

the-djmaze commented 2 years ago

It seems it generates the whole data folder in its default state again and again. The question is: Why???

Actions.php

        $sPassword = $oConfig->Get('security', 'admin_password', '');
        if (!$sPassword) {
            $sPassword = \substr(\base64_encode(\random_bytes(16)), 0, 12);
            Utils::saveFile($passfile, $sPassword . "\n");
            $oConfig->SetPassword($sPassword);
            $oConfig->Save();

This indicates that it doesn't find the application.ini, so we dive deeper.

snappymail/v/0.0.0/libraries/RainLoop/Config/AbstractConfig.php

    public function Load() : bool
    {
        if (\file_exists($this->sFile) && \is_readable($this->sFile))
        {
            if ($this->loadDataFromCache())
            {

Is there a file cache that PHP still thinks that the file does not exist or isn't readable?

Else:

    private function loadDataFromCache() : bool
    {
        if ($this->bUseApcCache)
        {

Do you have APP_USE_APCU_CACHE set to true?

Euphonique commented 2 years ago

It seems it generates the whole data folder in its default state again and again. The question is: Why???

Actions.php

      $sPassword = $oConfig->Get('security', 'admin_password', '');
      if (!$sPassword) {
          $sPassword = \substr(\base64_encode(\random_bytes(16)), 0, 12);
          Utils::saveFile($passfile, $sPassword . "\n");
          $oConfig->SetPassword($sPassword);
          $oConfig->Save();

This indicates that it doesn't find the application.ini, so we dive deeper.

snappymail/v/0.0.0/libraries/RainLoop/Config/AbstractConfig.php

  public function Load() : bool
  {
      if (\file_exists($this->sFile) && \is_readable($this->sFile))
      {
          if ($this->loadDataFromCache())
          {

Is there a file cache that PHP still thinks that the file does not exist or isn't readable?

Else:

  private function loadDataFromCache() : bool
  {
      if ($this->bUseApcCache)
      {

Do you have APP_USE_APCU_CACHE set to true?

Interesting. I use opcache and switched it off for testing, but same problem. Also tried to comment the password generation out: The password now stays the same but despite getting the Auth Error.

the-djmaze commented 2 years ago

@Euphonique try to modify snappymail/v/0.0.0/libraries/RainLoop/Config/AbstractConfig.php

Then something like:

    public function Load() : bool
    {
        if (\file_exists($this->sFile) && \is_readable($this->sFile))
        {
            // ....
        } else {
            \error_log("Failed to load config {$this->sFile}");
        }

You could add more tests there to figure it out

Euphonique commented 2 years ago

@Euphonique try to modify snappymail/v/0.0.0/libraries/RainLoop/Config/AbstractConfig.php

Then something like:

  public function Load() : bool
  {
      if (\file_exists($this->sFile) && \is_readable($this->sFile))
      {
          // ....
      } else {
          \error_log("Failed to load config {$this->sFile}");
      }

You could add more tests there to figure it out

Thanks for your help once again, but no new error in logfile except the Auth Error. :/ Any further ideas? If you want and it helps you to track down what's wrong I could give you ftp access to the files. It's really strange. Rainloop on the same webspace and server config works without problems.

the-djmaze commented 2 years ago

Does it work with 2.15.3?

Euphonique commented 2 years ago

Thanks for asking, but no luck so far. Tried 2.15.2 and stumbled upon the bug with the missing password file, too. Good to see you fixed it really fast. :) But can't logging in admin panel in 2.15.3 either. Tried different browsers, even mobile to exclude it's no bug on client side, too. Disabled php cache, SSL.. It drives me nuts, not finding what's causing this. It really seems snappymail resets the application.ini to defaults everytime I load the page. I even took the write permissions from the file and then it stays untouched. But can't login. The only error I get from my apache log is this:

[Sat May 14 13:35:15.891476 2022] [proxy_fcgi:error] [pid 1150310] [client xxx.xxx.xxx.xxx:50423] AH01071: Got error 'PHP message: SERVICE WARNING: AuthError[102]'

Euphonique commented 2 years ago

Guess snappymail somehow fails to find or to load the application.ini (maybe the whole data folder) and thinks it's not present, then generating a new one, overwriting the file with the defaults. But I don't know why.

the-djmaze commented 2 years ago

What happens if you modify https://github.com/the-djmaze/snappymail/blob/e6ea47e75f4c207c6a4373649f996933ca085d84/snappymail/v/0.0.0/app/libraries/RainLoop/Config/AbstractConfig.php#L182-L185

into

        if (!\file_exists($this->sFile)) {
            \error_log("{$this->sFile} does not exists");
        }
        if (!\is_readable($this->sFile)) {
            \error_log("{$this->sFile} not readable");
        }
        if (\file_exists($this->sFile) && \is_readable($this->sFile))
        {
            if ($this->loadDataFromCache())
            {
                \error_log("{$this->sFile} loaded from cache");

And check your php error log

Euphonique commented 2 years ago

``> What happens if you modify

https://github.com/the-djmaze/snappymail/blob/e6ea47e75f4c207c6a4373649f996933ca085d84/snappymail/v/0.0.0/app/libraries/RainLoop/Config/AbstractConfig.php#L182-L185

into

      if (!\file_exists($this->sFile)) {
          \error_log("{$this->sFile} does not exists");
      }
      if (!\is_readable($this->sFile)) {
          \error_log("{$this->sFile} not readable");
      }
      if (\file_exists($this->sFile) && \is_readable($this->sFile))
      {
          if ($this->loadDataFromCache())
          {
              \error_log("{$this->sFile} loaded from cache");

And check your php error log

Thanks, but only the known auth error:

[Tue May 17 14:55:40.874231 2022] [proxy_fcgi:error] [pid 1372633] [client XXX.XXX.XXX.XXX:56908] AH01071: Got error 'PHP message: SERVICE WARNING: AuthError[102]'

the-djmaze commented 2 years ago

That is weird. As if PHP never receives updated/changed files. Is there an aggressive PHP cache (or file cache) in effect that doesn't compile changes into bytecode and sticks with the old files?

I only have this problem sometimes with PHP OPcache and then i must:

  1. delete the file
  2. reload page and see it crash
  3. upload the file again

or:

  1. flush the full OPcache
  2. let it reload all php scripts over again
Euphonique commented 2 years ago

That is weird. As if PHP never receives updated/changed files. Is there an aggressive PHP cache (or file cache) in effect that doesn't compile changes into bytecode and sticks with the old files?

I only have this problem sometimes with PHP OPcache and then i must:

  1. delete the file
  2. reload page and see it crash
  3. upload the file again

or:

  1. flush the full OPcache
  2. let it reload all php scripts over again

Yeah, it's really weird. I disabled the opcache for this domain, cleared opcache, restarted apache, put 

opcache_invalidate(__FILE__, true);
opcache_reset();

in index.php file to see if something changes.. Nothing.. Still only got error: [Mon May 23 09:49:43.016068 2022] [proxy_fcgi:error] [pid 1664968] [client XXX.XXX.XXX.XXX:61816] AH01071: Got error 'PHP message: SERVICE WARNING: AuthError[102]'

I have no clue what's going on here. The username is 'admin' right? and the TOTP code field can be empty if not configured?

Euphonique commented 2 years ago

Whoa! Wait! It works!!! Getting into admin panel now! I had the following php extension disabled: parse_ini_file I enabled it and now it works.. How stupid.. I don't know why it was disabled by default, never disabled it by myself.

Euphonique commented 2 years ago

Thanks for your help! And sorry for this stupid error. Maybe it's possible to check if all nessesary php extensions are enabled and give a more helpful error when not? Maybe a page which shows up, when initializing snappymail the first time like in the admin panel for the optional extensions?

And one other question: There are two rainloop plugins not present in snappymail yet:

froxlor-change-password
video-on-login-screen

Is it possible to port them to snappymail? I tried to copy them in the plugin folder but then snappymail says it can not connect to repository.

the-djmaze commented 2 years ago

Great you found it!

froxlor-change-password

I can take a look at it

video-on-login-screen

Read #290

Euphonique commented 2 years ago

Great you found it!

froxlor-change-password

I can take a look at it

video-on-login-screen

Read #290

Great! Maybe I try to migrate the video plugin, and let you know if it works. Guess it should be possible without jquery. Does a template for plugins exist and what are the differencies to the rainloop plugins?

And I work on a clean and modern theme for snappymail. Maybe you would like to add it, when it‘s ready. :)

the-djmaze commented 2 years ago

Whoa! Wait! It works!!! Getting into admin panel now! I had the following php extension disabled: parse_ini_file I enabled it and now it works.. How stupid.. I don't know why it was disabled by default, never disabled it by myself.