Bench update error - Module import failed for UserRole (frappe.core.doctype.userrole.userrole)

ERPNext
1

Hello Team,

I got below user module error after updating bench. I have also studied nabin post to run first patch and then use bench upgrade command but still it not resolved.

Migrating silafrica
Executing frappe.patches.v7_2.setup_custom_perms #2017-01-19 in silafrica (93126b542d2d71a2)
Traceback (most recent call last):
File “/usr/lib64/python2.7/runpy.py”, line 162, in _run_module_as_main
“main”, fname, loader, pkg_name)
File “/usr/lib64/python2.7/runpy.py”, line 72, in _run_code
exec code in run_globals
File “/home/frappe/frappe-bench/apps/frappe/frappe/utils/bench_helper.py”, line 79, in
main()
File “/home/frappe/frappe-bench/apps/frappe/frappe/utils/bench_helper.py”, line 16, in main
click.Group(commands=commands)(prog_name=‘bench’)
File “/home/frappe/frappe-bench/env/lib/python2.7/site-packages/click/core.py”, line 716, in call
return self.main(*args, **kwargs)
File “/home/frappe/frappe-bench/env/lib/python2.7/site-packages/click/core.py”, line 696, in main
rv = self.invoke(ctx)
File “/home/frappe/frappe-bench/env/lib/python2.7/site-packages/click/core.py”, line 1060, in invoke
return _process_result(sub_ctx.command.invoke(sub_ctx))
File “/home/frappe/frappe-bench/env/lib/python2.7/site-packages/click/core.py”, line 1060, in invoke
return _process_result(sub_ctx.command.invoke(sub_ctx))
File “/home/frappe/frappe-bench/env/lib/python2.7/site-packages/click/core.py”, line 889, in invoke
return ctx.invoke(self.callback, **ctx.params)
File “/home/frappe/frappe-bench/env/lib/python2.7/site-packages/click/core.py”, line 534, in invoke
return callback(*args, **kwargs)
File “/home/frappe/frappe-bench/env/lib/python2.7/site-packages/click/decorators.py”, line 17, in new_func
return f(get_current_context(), *args, **kwargs)
File “/home/frappe/frappe-bench/apps/frappe/frappe/commands/init.py”, line 24, in _func
ret = f(frappe._dict(ctx.obj), *args, **kwargs)
File “/home/frappe/frappe-bench/apps/frappe/frappe/commands/site.py”, line 210, in migrate
migrate(context.verbose, rebuild_website=rebuild_website)
File “/home/frappe/frappe-bench/apps/frappe/frappe/migrate.py”, line 31, in migrate
frappe.modules.patch_handler.run_all()
File “/home/frappe/frappe-bench/apps/frappe/frappe/modules/patch_handler.py”, line 29, in run_all
if not run_single(patchmodule = patch):
File “/home/frappe/frappe-bench/apps/frappe/frappe/modules/patch_handler.py”, line 63, in run_single
return execute_patch(patchmodule, method, methodargs)
File “/home/frappe/frappe-bench/apps/frappe/frappe/modules/patch_handler.py”, line 83, in execute_patch
frappe.get_attr(patchmodule.split()[0] + “.execute”)()
File “/home/frappe/frappe-bench/apps/frappe/frappe/patches/v7_2/setup_custom_perms.py”, line 16, in execute
standard_perms = get_standard_permissions(d.name)
File “/home/frappe/frappe-bench/apps/frappe/frappe/core/page/permission_manager/permission_manager.py”, line 123, in get_standard_permissions
frappe.only_for(“System Manager”)
File “/home/frappe/frappe-bench/apps/frappe/frappe/init.py”, line 457, in only_for
myroles = set(get_roles())
File “/home/frappe/frappe-bench/apps/frappe/frappe/init.py”, line 362, in get_roles
return get_user().get_roles()
File “/home/frappe/frappe-bench/apps/frappe/frappe/init.py”, line 350, in get_user
local.user_perms = UserPermissions(local.session.user)
File “/home/frappe/frappe-bench/apps/frappe/frappe/utils/user.py”, line 37, in init
self.setup_user()
File “/home/frappe/frappe-bench/apps/frappe/frappe/utils/user.py”, line 53, in setup_user
user_doc = frappe.cache().hget(“user_doc”, self.name, get_user_doc)
File “/home/frappe/frappe-bench/apps/frappe/frappe/utils/redis_wrapper.py”, line 171, in hget
value = generator()
File “/home/frappe/frappe-bench/apps/frappe/frappe/utils/user.py”, line 43, in get_user_doc
user = frappe.get_doc(“User”, self.name).as_dict()
File “/home/frappe/frappe-bench/apps/frappe/frappe/init.py”, line 603, in get_doc
return frappe.model.document.get_doc(arg1, arg2)
File “/home/frappe/frappe-bench/apps/frappe/frappe/model/document.py”, line 51, in get_doc
return controller(arg1, arg2)
File “/home/frappe/frappe-bench/apps/frappe/frappe/model/document.py”, line 84, in init
self.load_from_db()
File “/home/frappe/frappe-bench/apps/frappe/frappe/model/document.py”, line 130, in load_from_db
self.set(df.fieldname, children)
File “/home/frappe/frappe-bench/apps/frappe/frappe/model/base_document.py”, line 122, in set
self.extend(key, value)
File “/home/frappe/frappe-bench/apps/frappe/frappe/model/base_document.py”, line 148, in extend
self.append(key, v)
File “/home/frappe/frappe-bench/apps/frappe/frappe/model/base_document.py”, line 136, in append
value = self._init_child(value, key)
File “/home/frappe/frappe-bench/apps/frappe/frappe/model/base_document.py”, line 163, in _init_child
value = get_controller(value[“doctype”])(value)
File “/home/frappe/frappe-bench/apps/frappe/frappe/model/base_document.py”, line 34, in get_controller
module = load_doctype_module(doctype, module_name)
File “/home/frappe/frappe-bench/apps/frappe/frappe/modules/utils.py”, line 184, in load_doctype_module
raise ImportError, ‘Module import failed for {0} ({1})’.format(doctype, module_name)
ImportError: Module import failed for UserRole (frappe.core.doctype.userrole.userrole)

2

Hi @Harsh_Mehta

Can you open patch log list and check the patch frappe.patches.v8_0.rename_page_role_to_has_role is executed or not

Thanks

3

i have the same error

4

Hello Rohit,

Thanks for looking into it. I have opened patches.txt file from frappe directory. and it seems like below.

execute:frappe.db.sql(“”“update tabPatch Log set patch=replace(patch, ‘.4_0.’, ‘.v4_0.’)”“”) #2014-05-12
frappe.patches.v5_0.convert_to_barracuda_and_utf8mb4
execute:frappe.utils.global_search.setup_global_search_table()
frappe.patches.v8_0.update_global_search_table
frappe.patches.v7_0.update_auth
frappe.patches.v7_1.rename_scheduler_log_to_error_log
frappe.patches.v6_1.rename_file_data
frappe.patches.v7_0.re_route #2016-06-27
frappe.patches.v7_2.remove_in_filter
execute:frappe.reload_doc(‘core’, ‘doctype’, ‘doctype’, force=True) #2017-03-09
execute:frappe.reload_doc(‘core’, ‘doctype’, ‘docfield’, force=True) #2017-03-03
execute:frappe.reload_doc(‘core’, ‘doctype’, ‘docperm’) #2017-03-03
frappe.patches.v8_0.drop_is_custom_from_docperm
frappe.patches.v8_0.drop_in_dialog
frappe.patches.v8_0.update_published_in_global_search
execute:frappe.reload_doc(‘core’, ‘doctype’, ‘custom_docperm’)
frappe.patches.v8_0.rename_page_role_to_has_role

I didn’t found patch log file and it were in backend but ERP not working so i can’t found it.

5

Hi @Harsh_Mehta

Thanks for sharing the details.
Have fixed the patch can you pull the latest code and check

6

Hi Rohit,

Thank you so much it resolved my problem but after login my desk is not coming it shows me error in console developer log.

SyntaxError: invalid property id

frappe.boot = {{ boot }};

7

Hi @Harsh_Mehta

Please run below commands
bench clear-cache
bench build
bench migrate

8

Thank you rohit but it still give me error.

9

Please share terminal and browser’s console log with complete traceback

10

Hello @rohit_w
No terminal traceback error is there.

Please see attached image.

ipmsgclip_r_1489671547_0.png702×515 20.8 KB

11

Hi @Harsh_Mehta

It’s difficult to identified the issue without traceback
If possible can you check web.error.log and worker.error.log
Path for log is: frappe-bench/logs/, to view log use command tail -f web.error.log

12

Hello Rohit,

Worker.error.log is empty. and web.error.log have below contents and those content are before upgrade to new version.

[2017-03-16 13:23:47 +0000] [12177] [INFO] Handling signal: term
[2017-03-16 13:23:47 +0000] [12251] [INFO] Worker exiting (pid: 12251)
[2017-03-16 13:23:47 +0000] [12252] [INFO] Worker exiting (pid: 12252)
[2017-03-16 13:23:48 +0000] [12177] [INFO] Shutting down: Master
[2017-03-16 13:23:55 +0000] [14866] [INFO] Starting gunicorn 19.6.0
[2017-03-16 13:23:55 +0000] [14866] [INFO] Listening at: http://127.0.0.1:8000 (14866)
[2017-03-16 13:23:55 +0000] [14866] [INFO] Using worker: sync
[2017-03-16 13:23:55 +0000] [14876] [INFO] Booting worker with pid: 14876
[2017-03-16 13:23:55 +0000] [14882] [INFO] Booting worker with pid: 14882
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git

13

Hi @Harsh_Mehta

Did you restart the supervisor?
sudo supervisorctl restart all

14

Yeah I have restarted supervisor but it not working.

15

Please, Rohit help me for how to resolve this console error as after apply your command it still not working.

16

I found below error in Web.error.log file.

[2017-03-17 04:08:54 +0000] [17057] [INFO] Handling signal: term
[2017-03-17 04:08:54 +0000] [17113] [INFO] Worker exiting (pid: 17113)
[2017-03-17 04:08:54 +0000] [17118] [INFO] Worker exiting (pid: 17118)
[2017-03-17 04:08:54 +0000] [17057] [INFO] Shutting down: Master
[2017-03-17 04:08:57 +0000] [22081] [INFO] Starting gunicorn 19.6.0
[2017-03-17 04:08:57 +0000] [22081] [INFO] Listening at: http://127.0.0.1:8000 (22081)
[2017-03-17 04:08:57 +0000] [22081] [INFO] Using worker: sync
[2017-03-17 04:08:57 +0000] [22153] [INFO] Booting worker with pid: 22153
[2017-03-17 04:08:57 +0000] [22154] [INFO] Booting worker with pid: 22154
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git
fatal: Not a git repository (or any of the parent directories): .git

17

I found below error in Work.error.log file.

04:29:01 short: frappe.utils.background_jobs.execute_job(async=True, event=u’all’, job_name=u’frappe.email.queue.flush’, kwargs={}, method=u’frappe.email.queue.flush’, site=u’silafrica’, user=u’Administrator’) (34e48723-7b36-4404-863b-55ecc705f02f)
04:29:01 short: Job OK (34e48723-7b36-4404-863b-55ecc705f02f)
04:29:01 Result is kept for 500 seconds
04:29:01
04:29:01 *** Listening on short…
04:29:01 short: frappe.utils.background_jobs.execute_job(async=True, event=u’all’, job_name=u’frappe.email.doctype.email_account.email_account.pull’, kwargs={}, method=u’frappe.email.doctype.email_account.email_account.pull’, site=u’silafrica’, user=u’Administrator’) (95debd03-cd34-4c2e-a4be-34b66badf6a1)
04:29:01 short: Job OK (95debd03-cd34-4c2e-a4be-34b66badf6a1)
04:29:01 Result is kept for 500 seconds
04:29:01
04:29:01 *** Listening on short…
04:29:01 short: frappe.utils.background_jobs.execute_job(async=True, event=u’all’, job_name=u’frappe.email.doctype.email_account.email_account.notify_unreplied’, kwargs={}, method=u’frappe.email.doctype.email_account.email_account.notify_unreplied’, site=u’silafrica’, user=u’Administrator’) (37e0ad03-8f32-4550-983b-313429c256fd)
04:29:01 short: Job OK (37e0ad03-8f32-4550-983b-313429c256fd)
04:29:01 Result is kept for 500 seconds
04:29:01
04:29:01 *** Listening on short…
04:29:01 short: frappe.utils.background_jobs.execute_job(async=True, event=u’all’, job_name=u’frappe.oauth.delete_oauth2_data’, kwargs={}, method=u’frappe.oauth.delete_oauth2_data’, site=u’silafrica’, user=u’Administrator’) (2f01acae-b4a4-436a-ace5-85b7762544f8)
04:29:01 short: Job OK (2f01acae-b4a4-436a-ace5-85b7762544f8)
04:29:01 Result is kept for 500 seconds
04:29:01
04:29:01 *** Listening on short…
04:29:01 short: frappe.utils.background_jobs.execute_job(async=True, event=u’all’, job_name=u’frappe.integrations.doctype.razorpay_settings.razorpay_settings.capture_payment’, kwargs={}, method=u’frappe.integrations.doctype.razorpay_settings.razorpay_settings.capture_payment’, site=u’silafrica’, user=u’Administrator’) (f3c19027-093f-415e-b0b5-4454b9610a94)
04:29:01 short: Job OK (f3c19027-093f-415e-b0b5-4454b9610a94)
04:29:01 Result is kept for 500 seconds
04:29:01
04:29:01 *** Listening on short…

18

Hi @Harsh_Mehta

Above logs didn’t have anything related to issue
Please check log web.log, frappe.log, bench.log
If possible can you check which method system trying to execute from the browser’s console log’s network section, check request and response message.

19

Hello Rohit,

I checked network panel and it not getting a proper response when calling to desk page. it breaks response.

Frappe Desk 
<!-- hack! load background image asap, before desktop is rendered -->


<script type="text/javascript" src="/assets/frappe/js/lib/jquery/jquery.min.js"></script>

<script type="text/javascript">
window._version_number = "{{ build_version }}";
// browser support
window.app = true;
window.dev_server = 0;

if(!window.frappe) window.frappe = {};

frappe.boot = {{ boot }};

frappe.csrf_token = "{{ csrf_token }}";

</script>
20

Hello Rohit,

There will be no error in bench.log file.I found below error in web.log and frappe.log file.

Web.log content

y", line 115, in get_app_branch
shell=True).strip()
File “/usr/lib64/python2.7/subprocess.py”, line 575, in check_output
raise CalledProcessError(retcode, cmd, output=output)
CalledProcessError: Command ‘cd …/apps/erpnextplus && git rev-parse --abbrev-ref HEAD’ returned non-zero exit status 128

Traceback (most recent call last):
File “/home/frappe/frappe-bench/apps/frappe/frappe/website/context.py”, line 46, in update_controller_context
ret = module.get_context(context)
File “/home/frappe/frappe-bench/apps/frappe/frappe/www/desk.py”, line 21, in get_context
boot = frappe.sessions.get()
File “/home/frappe/frappe-bench/apps/frappe/frappe/sessions.py”, line 150, in get
bootinfo = get_bootinfo()
File “/home/frappe/frappe-bench/apps/frappe/frappe/boot.py”, line 65, in get_bootinfo
bootinfo.versions = {k: v[‘version’] for k, v in get_versions().items()}
File “/home/frappe/frappe-bench/apps/frappe/frappe/utils/change_log.py”, line 97, in get_versions
“branch”: get_app_branch(app)
File “/home/frappe/frappe-bench/apps/frappe/frappe/utils/change_log.py”, line 115, in get_app_branch
shell=True).strip()
File “/usr/lib64/python2.7/subprocess.py”, line 575, in check_output
raise CalledProcessError(retcode, cmd, output=output)
CalledProcessError: Command ‘cd …/apps/erpnextplus && git rev-parse --abbrev-ref HEAD’ returned non-zero exit status 128

Traceback (most recent call last):
File “/home/frappe/frappe-bench/apps/frappe/frappe/website/context.py”, line 46, in update_controller_context
ret = module.get_context(context)
File “/home/frappe/frappe-bench/apps/frappe/frappe/www/desk.py”, line 21, in get_context
boot = frappe.sessions.get()
File “/home/frappe/frappe-bench/apps/frappe/frappe/sessions.py”, line 150, in get
bootinfo = get_bootinfo()
File “/home/frappe/frappe-bench/apps/frappe/frappe/boot.py”, line 65, in get_bootinfo
bootinfo.versions = {k: v[‘version’] for k, v in get_versions().items()}
File “/home/frappe/frappe-bench/apps/frappe/frappe/utils/change_log.py”, line 97, in get_versions
“branch”: get_app_branch(app)
File “/home/frappe/frappe-bench/apps/frappe/frappe/utils/change_log.py”, line 115, in get_app_branch
shell=True).strip()
File “/usr/lib64/python2.7/subprocess.py”, line 575, in check_output
raise CalledProcessError(retcode, cmd, output=output)
CalledProcessError: Command ‘cd …/apps/erpnextplus && git rev-parse --abbrev-ref HEAD’ returned non-zero exit status 128

Traceback (most recent call last):
File “/home/frappe/frappe-bench/apps/frappe/frappe/website/context.py”, line 46, in update_controller_context
ret = module.get_context(context)
File “/home/frappe/frappe-bench/apps/frappe/frappe/www/desk.py”, line 21, in get_context
boot = frappe.sessions.get()
File “/home/frappe/frappe-bench/apps/frappe/frappe/sessions.py”, line 150, in get
bootinfo = get_bootinfo()
File “/home/frappe/frappe-bench/apps/frappe/frappe/boot.py”, line 65, in get_bootinfo
bootinfo.versions = {k: v[‘version’] for k, v in get_versions().items()}
File “/home/frappe/frappe-bench/apps/frappe/frappe/utils/change_log.py”, line 97, in get_versions
“branch”: get_app_branch(app)
File “/home/frappe/frappe-bench/apps/frappe/frappe/utils/change_log.py”, line 115, in get_app_branch
shell=True).strip()
File “/usr/lib64/python2.7/subprocess.py”, line 575, in check_output
raise CalledProcessError(retcode, cmd, output=output)
CalledProcessError: Command ‘cd …/apps/erpnextplus && git rev-parse --abbrev-ref HEAD’ returned non-zero exit status 128

Traceback (most recent call last):
File “/home/frappe/frappe-bench/apps/frappe/frappe/website/context.py”, line 46, in update_controller_context
ret = module.get_context(context)
File “/home/frappe/frappe-bench/apps/frappe/frappe/www/desk.py”, line 21, in get_context
boot = frappe.sessions.get()
File “/home/frappe/frappe-bench/apps/frappe/frappe/sessions.py”, line 150, in get
bootinfo = get_bootinfo()
File “/home/frappe/frappe-bench/apps/frappe/frappe/boot.py”,

frappe.log

[DEBUG] 2017-03-17 09:57:24,029 | /home/frappe/frappe-bench/apps/frappe/frappe/utils/scheduler.py:
Site: silafrica
Queued events for site silafrica