Stuck at login for Administrative User (E Logo)

ERPNext
1

Has anyone encountered this before, not been able to login after completing the first install, and logging in for the first time?

image
image1501×1082 55.3 KB

Worker and Nginx Version: v14.11.0
frappe-socketio: v14.20.0

The ‘common_site_config.json’ file is correctly populated and the assets directory also looks to be correct.

It just get’s stuck at the logo and does nothing more at login, clearing cache and all the usual things on the browser side has no affect.

Just to note, this is not an old install or an update, this is a fresh install. Just starting to use ERPNext for the first time.

The issue is occurring on Kubernetes, but not on Docker.

Just seen someone else has a similar issue ages ago:

And another, not too long ago:

Running bench watch, build, etc…has not resolved the issue, so posting for more suggestions or insights to what might be missing.

Digging deeper into this, I see that it is a regular error too, here are more people with the same issue.

Update: I just spun up version 13, and this issue completely disappears, can confirm it is a v14 thing only! I can also confirm that you are more likely to reproduce this error if you completely clear the browser application cache + perform a empty-cache/hard-reload and attempt to login. So even for those who think they have it working, just try clearing your browser cache and double check it really works. Please note “Application Cache” is not that same as the browser history.

3

Logs and logs…

Backend - appears twice

/usr/local/lib/python3.10/functools.py:981: UserWarning: The 'filters_config' hook used to add custom operators is not yet implemented in frappe.db.query engine. Use db_query (frappe.get_list) instead.
  val = self.func(instance)

Frontend logs look heathly - lots of 200 HTTP status codes … sample of my logs:

10.2.0.44 - - [23/Dec/2022:14:57:21 +0000] "POST / HTTP/1.1" 200 13 "https://erp.mergelabs.io/login" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/108.0.0.0 Safari/537.36" "127.0.0.1"
10.2.0.44 - - [23/Dec/2022:14:57:21 +0000] "POST /socket.io/?EIO=4&transport=polling&t=OK_VHJ1&sid=m9U4A8rab6ptF4ItAAAU HTTP/1.1" 200 2 "https://erp.mergelabs.io/login" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/108.0.0.0 Safari/537.36" "127.0.0.1"
10.2.0.44 - - [23/Dec/2022:14:57:21 +0000] "GET /api/method/frappe.realtime.get_user_info?sid=Guest HTTP/1.1" 200 45 "-" "node-superagent/3.8.3" "127.0.0.1"
10.2.0.44 - - [23/Dec/2022:14:57:21 +0000] "GET /socket.io/?EIO=4&transport=polling&t=OK_VHJ2&sid=m9U4A8rab6ptF4ItAAAU HTTP/1.1" 200 32 "https://erp.mergelabs.io/login" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/108.0.0.0 Safari/537.36" "127.0.0.1"

Web Socket Log, only this appears and nothing else:

(node:1) [DEP0066] DeprecationWarning: OutgoingMessage.prototype._headers is deprecated
(Use `node --trace-deprecation ...` to show where the warning was created)

Scheduler - Appears once, nothing else

/usr/local/lib/python3.10/functools.py:981: UserWarning: The 'filters_config' hook used to add custom operators is not yet implemented in frappe.db.query engine. Use db_query (frappe.get_list) instead.
  val = self.func(instance)

Queues - now and again this error appears:

For Default Queue:

  File "/home/frappe/frappe-bench/apps/frappe/frappe/database/database.py", line 358, in sql_list
    return self.sql(query, values, **kwargs, debug=debug, pluck=True)
  File "/home/frappe/frappe-bench/apps/frappe/frappe/database/postgres/database.py", line 199, in sql
    return super().sql(modify_query(query), modify_values(values), *args, **kwargs)
  File "/home/frappe/frappe-bench/apps/frappe/frappe/database/database.py", line 240, in sql
    traceback.print_stack()
Error in query:
date/time field value out of range: "0000-00-00"
LINE 4:    and (end_of_life is null or end_of_life='0000-00-00' or e...

For Long Queue:

  File "/home/frappe/frappe-bench/apps/frappe/frappe/query_builder/utils.py", line 76, in execute_query
    return frappe.db.sql(query, params, *args, **kwargs)  # nosemgrep
  File "/home/frappe/frappe-bench/apps/frappe/frappe/database/postgres/database.py", line 199, in sql
    return super().sql(modify_query(query), modify_values(values), *args, **kwargs)
  File "/home/frappe/frappe-bench/apps/frappe/frappe/database/database.py", line 240, in sql
    traceback.print_stack()
Error in query:
column "tabStock Entry.name" must appear in the GROUP BY clause or be used in an aggregate function
LINE 1: SELECT "tabStock Entry"."name","tabStock Entry"."company","t...

For Short Queue - only this:

15:16:24 Worker rq:worker:5facec02ffe047e6b7ec0fdbc3faee36.mergelabs-erp-queue-short-deployment-5cdcf74b6b-mgwfz.6.home-frappe-frappe-bench:short: started, version 1.11.1
15:16:24 Subscribing to channel rq:pubsub:5facec02ffe047e6b7ec0fdbc3faee36.mergelabs-erp-queue-short-deployment-5cdcf74b6b-mgwfz.6.home-frappe-frappe-bench:short
15:16:25 *** Listening on home-frappe-frappe-bench:short...
15:16:25 Cleaning registries for queue: home-frappe-frappe-bench:short
  • But mostly in the queues it states:
15:17:30 home-frappe-frappe-bench:default: Job OK (d7d97712-216d-4748-96f1-591f9f68766c)
15:17:30 Result is kept for 600 seconds
15:17:30 home-frappe-frappe-bench:default: frappe.utils.background_jobs.execute_job(event=None, is_async=True, job_name='frappe.core.doctype.scheduled_job_type.scheduled_job_type.run_scheduled_jo..., kwargs={'job_type': 'erpnext.utilities.doctype.video.video.update_youtube_data'}, method='frappe.core.doctype.scheduled_job_type.scheduled_job_type.run_scheduled_jo..., site='-redacted-', user='Administrator') (d8a00742-adbc-4128-be00-8878087e0a4e)
/usr/local/lib/python3.10/functools.py:981: UserWarning: The 'filters_config' hook used to add custom operators is not yet implemented in frappe.db.query engine. Use db_query (frappe.get_list) instead.
  val = self.func(instance)
15:17:30 home-frappe-frappe-bench:default: Job OK (d8a00742-adbc-4128-be00-8878087e0a4e)
15:17:30 Result is kept for 600 seconds
15:17:30 home-frappe-frappe-bench:default: frappe.utils.background_jobs.execute_job(event=None, is_async=True, job_name='frappe.core.doctype.scheduled_job_type.scheduled_job_type.run_scheduled_jo..., kwargs={'job_type': 'erpnext.manufacturing.doctype.bom_update_log.bom_update_log.r..., method='frappe.core.doctype.scheduled_job_type.scheduled_job_type.run_scheduled_jo..., site='-redacted-', user='Administrator') (7ab8f292-677c-4d6b-91b8-53304f8f1be3)
/usr/local/lib/python3.10/functools.py:981: UserWarning: The 'filters_config' hook used to add custom operators is not yet implemented in frappe.db.query engine. Use db_query (frappe.get_list) instead.
  val = self.func(instance)
4

Try:

nvm use 16
bench build

And see if it works

5

Hey thanks @rtdany10 for the suggestion, however, from my original post you can see that I have already mentioned that trying these things have not resolved the issue.

Maybe it would be helpful that I mention that in the Kubernetes image that I’m running is:
Backend - frappe/erpnext-worker:v14.11.0
Frontend - frappe/erpnext-nginx:v14.11.0
Thus this command is not available in that particular format/environment.

I have tried this when building and install from scratch or in Docker too, but also by reading the original post, I have stated that the issue is in Kubernetes.

For records sake I have included the output when running those commands on the backend service:

$ nvm use 16
bash: nvm: command not found

$ bench build
Assets for Release v14.11.0 don't exist
✔ Application Assets Linked


yarn run v1.22.19
$ node esbuild --production --run-build-command
node:internal/modules/cjs/loader:988
  throw err;
  ^

Error: Cannot find module 'fast-glob'
Require stack:
- /home/frappe/frappe-bench/apps/frappe/esbuild/esbuild.js
- /home/frappe/frappe-bench/apps/frappe/esbuild/index.js
    at Function.Module._resolveFilename (node:internal/modules/cjs/loader:985:15)
    at Function.Module._load (node:internal/modules/cjs/loader:833:27)
    at Module.require (node:internal/modules/cjs/loader:1057:19)
    at require (node:internal/modules/cjs/helpers:103:18)
    at Object.<anonymous> (/home/frappe/frappe-bench/apps/frappe/esbuild/esbuild.js:4:14)
    at Module._compile (node:internal/modules/cjs/loader:1155:14)
    at Object.Module._extensions..js (node:internal/modules/cjs/loader:1209:10)
    at Module.load (node:internal/modules/cjs/loader:1033:32)
    at Function.Module._load (node:internal/modules/cjs/loader:868:12)
    at Module.require (node:internal/modules/cjs/loader:1057:19) {
  code: 'MODULE_NOT_FOUND',
  requireStack: [
    '/home/frappe/frappe-bench/apps/frappe/esbuild/esbuild.js',
    '/home/frappe/frappe-bench/apps/frappe/esbuild/index.js'
  ]
}
error Command failed with exit code 1.
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.
Traceback (most recent call last):
  File "/usr/local/bin/patched_bench_helper.py", line 48, in <module>
    raise SystemExit(main())
  File "/usr/local/bin/patched_bench_helper.py", line 43, in main
    frappe.utils.bench_helper.main()
  File "/home/frappe/frappe-bench/apps/frappe/frappe/utils/bench_helper.py", line 18, in main
    click.Group(commands=commands)(prog_name="bench")
  File "/home/frappe/frappe-bench/env/lib/python3.10/site-packages/click/core.py", line 829, in __call__
    return self.main(*args, **kwargs)
  File "/home/frappe/frappe-bench/env/lib/python3.10/site-packages/click/core.py", line 782, in main
    rv = self.invoke(ctx)
  File "/home/frappe/frappe-bench/env/lib/python3.10/site-packages/click/core.py", line 1259, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/home/frappe/frappe-bench/env/lib/python3.10/site-packages/click/core.py", line 1259, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/home/frappe/frappe-bench/env/lib/python3.10/site-packages/click/core.py", line 1066, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/home/frappe/frappe-bench/env/lib/python3.10/site-packages/click/core.py", line 610, in invoke
    return callback(*args, **kwargs)
  File "/home/frappe/frappe-bench/apps/frappe/frappe/commands/utils.py", line 82, in build
    bundle(mode, apps=apps, hard_link=hard_link, verbose=verbose, skip_frappe=skip_frappe)
  File "/home/frappe/frappe-bench/apps/frappe/frappe/build.py", line 257, in bundle
    frappe.commands.popen(command, cwd=frappe_app_path, env=get_node_env(), raise_err=True)
  File "/home/frappe/frappe-bench/apps/frappe/frappe/commands/__init__.py", line 98, in popen
    raise subprocess.CalledProcessError(return_, command)
subprocess.CalledProcessError: Command 'yarn run production --run-build-command' returned non-zero exit status 1.

Running the bench watch, build, etc… with the site option specified also does not result in anything fruitful.

However, I’m very much thankful for you input, if you have any other suggestions, perhaps I’ve missed a step or some important documentation that I have not read yet that I need to catch up with, please do not hesitate to add more please.

7

ERPNext v14 requires node 16. Check your node version and make sure it’s 16.
nvm use 16 was supposed to change your node version to 16 and then running bench build would have ideally solved the issue, but it seems nvm isn’t installed.

8

@rtdany10 you are correct NVM is not installed and by design, does not come installed on the backend image - frappe/erpnext-worker:v14.11.0

But I understand what you were getting at in regards to having/checking node installed, before running the bench command.

Updated: So if I run node -v I get the response:

v16.18.0

Not having NVM installed in this image is by design from what I can tell. The site is served by nginx and only works until the application cache is cleared, after the install/setup-wizard process, at which point it then always gets stuck as the logo screen (hence my call for help).

Keep in mind that this is a container image that has been built by the maintainers of Frappe/ERPNext and is not something that I have built or should attempt to change unless I build an image completely from scratch.

Install Notes can be found here: https://helm.erpnext.com/

One other observation is that during the setup-wizard, the JS and CSS scripts all have references to the apps (not app) folder and there are scripts that are included via the sourceMappingURL reference. Once the setup has completed, and the browser has had it’s cache cleared (or just another browser is used) any and all references in the previous scripts for sourceMappingURL have been removed and these apps scripts and libraries are no longer loaded in. This might explain to why, as long as I don’t clear the browser’s cache, that the site continues to work, and once I clear the cache, those files that were included from the apps directory are removed and then the site no longer works? Just my current running theory (poking in the dark here)

9

I’m having somewhat the same issue.

This is not a new install though, but it’s on v14, did a patch update in a docker setup. Now cannot log in, after pressing the log in button, I,m stuck on Verifying…

image

The error in the console is

image

Tried downgrading the docker image, but still same issue

Can’t see any relevant errors in the containers logs but I’ll post them here just in case

Any clue on how to get back into the system would be appreciated, cannot access my accounting data in this state.

Thanks

websocket container:

(node:1) [DEP0066] DeprecationWarning: OutgoingMessage.prototype._headers is deprecated
(Use `node --trace-deprecation ...` to show where the warning was created)

scheduler container:

/usr/local/lib/python3.10/functools.py:981: UserWarning: The 'filters_config' hook used to add custom operators is not yet implemented in frappe.db.query engine. Use db_query (frappe.get_list) instead.
  val = self.func(instance)

redis container:

1:C 30 Dec 2022 20:32:27.009 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
1:C 30 Dec 2022 20:32:27.009 # Redis version=6.2.8, bits=64, commit=00000000, modified=0, pid=1, just started
1:C 30 Dec 2022 20:32:27.009 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf
1:M 30 Dec 2022 20:32:27.009 * monotonic clock: POSIX clock_gettime
1:M 30 Dec 2022 20:32:27.010 * Running mode=standalone, port=6379.
1:M 30 Dec 2022 20:32:27.010 # Server initialized
1:M 30 Dec 2022 20:32:27.010 # WARNING Memory overcommit must be enabled! Without it, a background save or replication may fail under low memory condition. Being disabled, it can can also cause failures without low memory condition, see https://github.com/jemalloc/jemalloc/issues/1328. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
1:M 30 Dec 2022 20:32:27.010 * Loading RDB produced by version 6.2.8
1:M 30 Dec 2022 20:32:27.010 * RDB age 11 seconds
1:M 30 Dec 2022 20:32:27.010 * RDB memory usage when created 21.71 Mb
1:M 30 Dec 2022 20:32:27.108 # Done loading RDB, keys loaded: 120, keys expired: 0.
1:M 30 Dec 2022 20:32:27.108 * DB loaded from disk: 0.098 seconds
1:M 30 Dec 2022 20:32:27.108 * Ready to accept connections
1:M 30 Dec 2022 20:46:02.108 * 100 changes in 300 seconds. Saving...
1:M 30 Dec 2022 20:46:02.109 * Background saving started by pid 15
15:C 30 Dec 2022 20:46:02.262 * DB saved on disk
15:C 30 Dec 2022 20:46:02.263 * RDB: 2 MB of memory used by copy-on-write
1:M 30 Dec 2022 20:46:02.310 * Background saving terminated with success
1:M 30 Dec 2022 20:53:50.567 * 100 changes in 300 seconds. Saving...
1:M 30 Dec 2022 20:53:50.568 * Background saving started by pid 16
16:C 30 Dec 2022 20:53:50.687 * DB saved on disk
16:C 30 Dec 2022 20:53:50.688 * RDB: 1 MB of memory used by copy-on-write
1:M 30 Dec 2022 20:53:50.769 * Background saving terminated with success

queue-short container:

20:46:29 Worker rq:worker:6e81ef7a92be4ffa9a070caceeb0a55e.0bb9b50f74e3.7.home-frappe-frappe-bench:short: started, version 1.11.1
20:46:29 Subscribing to channel rq:pubsub:6e81ef7a92be4ffa9a070caceeb0a55e.0bb9b50f74e3.7.home-frappe-frappe-bench:short
20:46:29 *** Listening on home-frappe-frappe-bench:short...

queue-long container:

20:46:29 Worker rq:worker:4ac0ca45ee3e444ebe60151bdbd65be8.53411fd83281.7.home-frappe-frappe-bench:long: started, version 1.11.1
20:46:29 Subscribing to channel rq:pubsub:4ac0ca45ee3e444ebe60151bdbd65be8.53411fd83281.7.home-frappe-frappe-bench:long
20:46:29 *** Listening on home-frappe-frappe-bench:long...

queue-default container:

20:46:29 Worker rq:worker:fd9dbcf4b74d4a8a80ca8f765056abd8.d82f75891cbd.7.home-frappe-frappe-bench:default: started, version 1.11.1
20:46:29 Subscribing to channel rq:pubsub:fd9dbcf4b74d4a8a80ca8f765056abd8.d82f75891cbd.7.home-frappe-frappe-bench:default
20:46:29 *** Listening on home-frappe-frappe-bench:default...

frontend container:

/docker-entrypoint.sh: /docker-entrypoint.d/ is not empty, will attempt to perform configuration
/docker-entrypoint.sh: Looking for shell scripts in /docker-entrypoint.d/
/docker-entrypoint.sh: Launching /docker-entrypoint.d/frappe-entrypoint.sh
/docker-entrypoint.sh: Launching /docker-entrypoint.d/10-listen-on-ipv6-by-default.sh
10-listen-on-ipv6-by-default.sh: info: Getting the checksum of /etc/nginx/conf.d/default.conf
10-listen-on-ipv6-by-default.sh: info: /etc/nginx/conf.d/default.conf differs from the packaged version
/docker-entrypoint.sh: Launching /docker-entrypoint.d/20-envsubst-on-templates.sh
20-envsubst-on-templates.sh: Running envsubst on /etc/nginx/templates/default.conf.template to /etc/nginx/conf.d/default.conf
/docker-entrypoint.sh: Launching /docker-entrypoint.d/30-tune-worker-processes.sh
/docker-entrypoint.sh: Configuration complete; ready for start up
2022/12/30 20:47:32 [notice] 1#1: using the "epoll" event method
2022/12/30 20:47:32 [notice] 1#1: nginx/1.23.3
2022/12/30 20:47:32 [notice] 1#1: built by gcc 12.2.1 20220924 (Alpine 12.2.1_git20220924-r4) 
2022/12/30 20:47:32 [notice] 1#1: OS: Linux 5.15.0-56-generic
2022/12/30 20:47:32 [notice] 1#1: getrlimit(RLIMIT_NOFILE): 1048576:1048576
2022/12/30 20:47:32 [notice] 1#1: start worker processes
2022/12/30 20:47:32 [notice] 1#1: start worker process 36
2022/12/30 20:47:32 [notice] 1#1: start worker process 37
2022/12/30 20:47:32 [notice] 1#1: start worker process 38
2022/12/30 20:47:32 [notice] 1#1: start worker process 39
2022/12/30 20:47:32 [notice] 1#1: start worker process 40
2022/12/30 20:47:32 [notice] 1#1: start worker process 41
2022/12/30 20:47:32 [notice] 1#1: start worker process 42
2022/12/30 20:47:32 [notice] 1#1: start worker process 43

then a bunch of 200 status requests and the 500 status request that matches the error posted above

bakcend container:

[2022-12-30 20:46:29 +0000] [1] [INFO] Starting gunicorn 20.1.0
[2022-12-30 20:46:29 +0000] [1] [INFO] Listening at: http://0.0.0.0:8000 (1)
[2022-12-30 20:46:29 +0000] [1] [INFO] Using worker: gthread
[2022-12-30 20:46:29 +0000] [6] [INFO] Booting worker with pid: 6
[2022-12-30 20:46:29 +0000] [7] [INFO] Booting worker with pid: 7
/usr/local/lib/python3.10/functools.py:981: UserWarning: The 'filters_config' hook used to add custom operators is not yet implemented in frappe.db.query engine. Use db_query (frappe.get_list) instead.
  val = self.func(instance)
/usr/local/lib/python3.10/functools.py:981: UserWarning: The 'filters_config' hook used to add custom operators is not yet implemented in frappe.db.query engine. Use db_query (frappe.get_list) instead.
  val = self.func(instance)
10

ok, in the end, for me, it was a cache issue.

I logged in the console of the backend container, then issued the command bench --site SITE_NAME clear-cache

still had an error on the command line about

/usr/local/lib/python3.10/functools.py:981: UserWarning: The 'filters_config' hook used to add custom operators is not yet implemented in frappe.db.query engine. Use db_query (frappe.get_list) instead.
  val = self.func(instance)

But I am not able to log in without issues.

11

FINALLY !!! I figured out the issue that I was having with ERPNext after working on it for almost two months. It may not be relevant to everyone, but here it is:

ERPNext requires the presence of sourceMappingUrl entries at the end of their bundled JavaScript files. If you have an automatic minification process, such as Cloudflare’s auto minify feature or a proxy that removes sourceMappingUrl values from the end of the JS bundle files, the site will most likely not function correctly.

To fix this issue, try disabling any proxy or auto-minification processes. Hopefully this will resolve the problem.

If not, you may need to continue searching for a solution, so good luck… or consider paying the Frappe team for support, as they may not respond otherwise.

1 Like
12

Your Answer Was Very Helpfull. Thanks

13

Hi
disabled everything on cloudflare Speed section.
Also disabled proxies in DNS settings.
Still the same