Upgrade from v3 to v4 error

Hello everyone, I’m trying to upgrade instance of V3 to V4. When it gets to “installing frappe”, it stays there for a long time and exits with the following stacktrace

installing frappe
Compiling /home/erpnext/frappe-bench/env/build/gunicorn/gunicorn/workers/_gaiohttp.py ...
  File "/home/erpnext/frappe-bench/env/build/gunicorn/gunicorn/workers/_gaiohttp.py", line 64
    yield from self.wsgi.close()
             ^
SyntaxError: invalid syntax

Command /home/erpnext/frappe-bench/env/bin/python2.7 -c "import setuptools, tokenize;__file__='/home/erpnext/frappe-bench/env/build/mysql-python/setup.py';exec(compile(getattr(tokenize, 'open', open)(__file__).read().replace('\r\n', '\n'), __file__, 'exec'))" install --record /tmp/pip-t7E6yF-record/install-record.txt --single-version-externally-managed --compile --install-headers /home/erpnext/frappe-bench/env/include/site/python2.7 failed with error code 1 in /home/erpnext/frappe-bench/env/build/mysql-python
Storing debug log for failure in /home/erpnext/.pip/pip.log
Error: None
Traceback (most recent call last):
  File "/usr/local/bin/bench", line 9, in <module>
    load_entry_point('bench==0.1', 'console_scripts', 'bench')()
  File "/home/erpnext/bench-repo/bench/cli.py", line 29, in cli
    return bench()
  File "/usr/local/lib/python2.7/dist-packages/click/core.py", line 610, in __call__
    return self.main(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/click/core.py", line 590, in main
    rv = self.invoke(ctx)
  File "/usr/local/lib/python2.7/dist-packages/click/core.py", line 936, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/lib/python2.7/dist-packages/click/core.py", line 782, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/usr/local/lib/python2.7/dist-packages/click/core.py", line 416, in invoke
    return callback(*args, **kwargs)
  File "/home/erpnext/bench-repo/bench/cli.py", line 68, in init
    no_auto_update=no_auto_update, frappe_path=frappe_path, frappe_branch=frappe_branch)
  File "/home/erpnext/bench-repo/bench/utils.py", line 47, in init
    get_app('frappe', frappe_path, branch=frappe_branch, bench=path)
  File "/home/erpnext/bench-repo/bench/app.py", line 35, in get_app
    install_app(app, bench=bench)
  File "/home/erpnext/bench-repo/bench/app.py", line 53, in install_app
    find_links=find_links))
  File "/home/erpnext/bench-repo/bench/utils.py", line 59, in exec_cmd
    subprocess.check_call(cmd, cwd=cwd, shell=True)
  File "/usr/lib/python2.7/subprocess.py", line 540, in check_call
    raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command 'frappe-bench/env/bin/pip install -q  -e frappe-bench/apps/frappe' returned non-zero exit status 1

Any help will be appreciated

Please check and post the pip log (path in the traceback).

Pip.log https://docs.google.com/document/d/1-mNW3nSVIQs2erlRY4DcHA3pK34FbXIPrG6RU-hqatA/edit?usp=sharing

So somehow using I got frappe to install just fine. But then running bench migrate-3to4 /home/erpnext/erpnext
/home/erpnext/erpnext/ ends up in this error.

database backup taken - sites/erpnext/private/backups/20141019_50905975_database.sql.gz - on 2014-10-19 01:19:33.649649
Executing execute:frappe.db.sql(""“update tabPatch Log set patch=replace(patch, ‘.4_0.’, ‘.v4_0.’)”"") #2014-05-12 in erpnext (nexia)
Success
Executing execute:frappe.reload_doc(‘core’, ‘doctype’, ‘doctype’, force=True) #2014-01-24 in erpnext (nexia)
Success
Executing execute:frappe.reload_doc(‘core’, ‘doctype’, ‘docfield’, force=True) #2014-03-01 in erpnext (nexia)
Success
Executing execute:frappe.reload_doc(‘core’, ‘doctype’, ‘docperm’) #2014-06-04 in erpnext (nexia)
Success
Executing execute:frappe.reload_doc(‘core’, ‘doctype’, ‘page’) #2013-13-26 in erpnext (nexia)
Success
Executing execute:frappe.reload_doc(‘core’, ‘doctype’, ‘report’) #2014-06-03 in erpnext (nexia)
Success
Executing execute:frappe.reload_doc(‘core’, ‘doctype’, ‘version’) #2014-02-21 in erpnext (nexia)
Success
Executing execute:frappe.reload_doc(‘core’, ‘doctype’, ‘email_alert’) #2014-07-15 in erpnext (nexia)
Success
Executing execute:frappe.db.sql(“alter table tabSessions modify user varchar(255), engine=InnoDB”) in erpnext (nexia)
Success
Executing execute:frappe.db.sql(“delete from tabDocField where parent=‘0’”) in erpnext (nexia)
Success
Executing frappe.patches.v4_0.change_varchar_length in erpnext (nexia)
Success
Executing frappe.patches.v4_0.webnotes_to_frappe in erpnext (nexia)
Success
Executing execute:frappe.reset_perms(“Module Def”) in erpnext (nexia)
Success
Executing execute:import frappe.installer;frappe.installer.make_site_dirs() #2014-02-19 in erpnext (nexia)
Success
Executing frappe.patches.v4_0.rename_profile_to_user in erpnext (nexia)
Success
Executing frappe.patches.v4_0.deprecate_control_panel in erpnext (nexia)
Success
Executing frappe.patches.v4_0.remove_old_parent in erpnext (nexia)
Success
Executing frappe.patches.v4_0.rename_sitemap_to_route in erpnext (nexia)
Success
Executing frappe.patches.v4_0.website_sitemap_hierarchy in erpnext (nexia)
Success
Executing frappe.patches.v4_0.remove_index_sitemap in erpnext (nexia)
Success
Executing frappe.patches.v4_0.set_website_route_idx in erpnext (nexia)
Success
Executing frappe.patches.v4_0.add_delete_permission in erpnext (nexia)
Success
Executing frappe.patches.v4_0.set_todo_checked_as_closed in erpnext (nexia)
Success
Executing frappe.patches.v4_0.private_backups in erpnext (nexia)
Success
Executing frappe.patches.v4_0.set_module_in_report in erpnext (nexia)
Success
Executing frappe.patches.v4_0.update_datetime in erpnext (nexia)
Success
Executing frappe.patches.v4_0.file_manager_hooks in erpnext (nexia)
Success
Executing execute:frappe.get_doc(“User”, “Guest”).save() in erpnext (nexia)
Success
Executing frappe.patches.v4_0.update_custom_field_insert_after in erpnext (nexia)
Success
Executing frappe.patches.v4_0.deprecate_link_selects in erpnext (nexia)
Success
Executing frappe.patches.v4_0.set_user_gravatar in erpnext (nexia)
Success
Executing frappe.patches.v4_0.set_user_permissions in erpnext (nexia)
Success
Executing frappe.patches.v4_0.create_custom_field_for_owner_match in erpnext (nexia)
Success
Executing frappe.patches.v4_0.enable_scheduler_in_system_settings in erpnext (nexia)
Success
Executing execute:frappe.db.sql(“update tabReport set apply_user_permissions=1”) #2014-06-03 in erpnext (nexia)
Success
Executing frappe.patches.v4_0.replace_deprecated_timezones in erpnext (nexia)
Success
Executing execute:import frappe.website.render; frappe.website.render.clear_cache(“login”); #2014-06-10 in erpnext (nexia)
Success
Executing frappe.patches.v4_0.fix_attach_field_file_url in erpnext (nexia)
Success
Executing execute:frappe.reset_perms(“User”) #2014-06-13 in erpnext (nexia)
Success
Executing execute:frappe.db.sql(""“delete from tabUserRole where ifnull(parentfield, ‘’)=’’ or ifnull(role, ‘’)=’’”"") #2014-08-18 in erpnext (nexia)
Success
Executing frappe.patches.v4_0.remove_user_owner_custom_field in erpnext (nexia)
Success
Executing execute:frappe.delete_doc(“DocType”, “Website Template”) in erpnext (nexia)
Success
Executing execute:frappe.db.sql(""“update tabProperty Setter set property_type=‘Text’ where property in (‘options’, ‘default’)”"") #2014-06-20 in erpnext (nexia)
Success
Executing frappe.patches.v4_1.enable_outgoing_email_settings in erpnext (nexia)
Success
Executing execute:frappe.db.sql(""“update tabSingles set value=doctype where field=‘name’”"") #2014-07-04 in erpnext (nexia)
Success
Executing frappe.patches.v4_1.enable_print_as_pdf #2014-06-17 in erpnext (nexia)
Success
Executing execute:frappe.db.sql(""“update tabDocPerm set email=1 where parent=‘User’ and permlevel=0 and role=‘All’ and read=1 and apply_user_permissions=1"”") #2014-07-15 in erpnext (nexia)
Success
Executing execute:frappe.db.sql(""“update tabPrint Format set print_format_type=‘Client’ where ifnull(print_format_type, ‘’)=’’”"") #2014-07-28 in erpnext (nexia)
Success
Executing frappe.patches.v4_1.file_manager_fix in erpnext (nexia)
Success
Executing frappe.patches.v4_2.print_with_letterhead in erpnext (nexia)
Success
Executing execute:frappe.delete_doc(“DocType”, “Control Panel”, force=1) in erpnext (nexia)
Success
Executing execute:frappe.reload_doc(‘website’, ‘doctype’, ‘web_form’) #2014-09-04 in erpnext (nexia)
Success
Executing execute:frappe.reload_doc(‘website’, ‘doctype’, ‘web_form_field’) #2014-09-04 in erpnext (nexia)
Success
Executing frappe.patches.v4_2.refactor_website_routing in erpnext (nexia)
Traceback (most recent call last):
File “/home/erpnext/bench-repo/bench/migrate3to4.py”, line 106, in
main(args.site)
File “/home/erpnext/bench-repo/bench/migrate3to4.py”, line 39, in main
migrate(site)
File “/home/erpnext/bench-repo/bench/migrate3to4.py”, line 86, in migrate
latest()
File “/home/erpnext/frappe-bench/apps/frappe/frappe/cli.py”, line 67, in new_fn
return fn(*args, **new_kwargs)
File “/home/erpnext/frappe-bench/apps/frappe/frappe/cli.py”, line 423, in latest
frappe.modules.patch_handler.run_all()
File “/home/erpnext/frappe-bench/apps/frappe/frappe/modules/patch_handler.py”, line 25, in run_all
if not run_single(patchmodule = patch):
File “/home/erpnext/frappe-bench/apps/frappe/frappe/modules/patch_handler.py”, line 50, in run_single
return execute_patch(patchmodule, method, methodargs)
File “/home/erpnext/frappe-bench/apps/frappe/frappe/modules/patch_handler.py”, line 66, in execute_patch
frappe.get_attr(patchmodule.split()[0] + “.execute”)()
File “/home/erpnext/frappe-bench/apps/frappe/frappe/patches/v4_2/refactor_website_routing.py”, line 7, in execute
frappe.db.sql("drop table tabWebsite Route")
File “/home/erpnext/frappe-bench/apps/frappe/frappe/database.py”, line 121, in sql
self._cursor.execute(query)
File “/home/erpnext/frappe-bench/env/local/lib/python2.7/site-packages/MySQLdb/cursors.py”, line 205, in execute
self.errorhandler(self, exc, value)
File “/home/erpnext/frappe-bench/env/local/lib/python2.7/site-packages/MySQLdb/connections.py”, line 36, in defaulterrorhandler
raise errorclass, errorvalue
_mysql_exceptions.OperationalError: (1051, “Unknown table ‘nexia.tabWebsite Route’”)
Error: None
Traceback (most recent call last):
File “/usr/local/bin/bench”, line 9, in
load_entry_point(‘bench==0.1’, ‘console_scripts’, ‘bench’)()
File “/home/erpnext/bench-repo/bench/cli.py”, line 29, in cli
return bench()
File “/usr/local/lib/python2.7/dist-packages/click/core.py”, line 610, in call
return self.main(*args, **kwargs)
File “/usr/local/lib/python2.7/dist-packages/click/core.py”, line 590, in main
rv = self.invoke(ctx)
File “/usr/local/lib/python2.7/dist-packages/click/core.py”, line 936, in invoke
return _process_result(sub_ctx.command.invoke(sub_ctx))
File “/usr/local/lib/python2.7/dist-packages/click/core.py”, line 782, in invoke
return ctx.invoke(self.callback, **ctx.params)
File “/usr/local/lib/python2.7/dist-packages/click/core.py”, line 416, in invoke
return callback(*args, **kwargs)
File “/home/erpnext/bench-repo/bench/cli.py”, line 162, in migrate_3to4
site=path))
File “/home/erpnext/bench-repo/bench/utils.py”, line 59, in exec_cmd
subprocess.check_call(cmd, cwd=cwd, shell=True)
File “/usr/lib/python2.7/subprocess.py”, line 540, in check_call
raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command ‘env/bin/python /home/erpnext/bench-repo/bench/migrate3to4.py /home/erpnext/erpnext’ returned non-zero exit status 1

OK so I finally got it installed and upgraded. Phew!!! But accessing localhost gives “Internal Server Error”

What could be wrong this time around? And yes I followed the instruction to do production deployment

Share some logs. Its really hard to guess :slight_smile:

log from /var/log/nginx/error.log.1

2014/10/19 01:02:56 [notice] 5660#0: using inherited sockets from “6;”
2014/10/19 02:32:59 [emerg] 3876#0: unexpected “}” in /etc/nginx/nginx.conf:26
2014/10/19 02:33:52 [emerg] 1053#0: unexpected “}” in /etc/nginx/nginx.conf:26
2014/10/19 02:39:13 [emerg] 2481#0: unexpected “}” in /etc/nginx/nginx.conf:26
2014/10/19 02:39:32 [emerg] 2550#0: unexpected “}” in /etc/nginx/nginx.conf:26
2014/10/19 12:07:06 [emerg] 1051#0: unexpected “}” in /etc/nginx/nginx.conf:26

I’m not sure why that because the braces are just fine

OK so I fixed it. The line include /etc/nginx/conf.d/*.conf; didn’t have the closing semi-colons. I added that. Then I moved it to just below include mime.types;. So now the upgrade succeeded. I can access my data. Now to run through and see if there was any data inconsistency in the upgrade process

OK so restarting the server does NOT automatically restart the needed processes. What I mean is upon reboot, access localhost gives “Internal Server Error”

This is my gunicorn log

2014-10-19 16:19:55 [1259] [INFO] Starting gunicorn 17.5
2014-10-19 16:19:55 [1259] [INFO] Listening at: http://127.0.0.1:8000 (1259)
2014-10-19 16:19:55 [1259] [INFO] Using worker: sync
2014-10-19 16:19:55 [1301] [INFO] Booting worker with pid: 1301
2014-10-19 16:19:55 [1302] [INFO] Booting worker with pid: 1302
2014-10-19 16:20:13 [1302] [ERROR] Error handling request
Traceback (most recent call last):
File “/usr/lib/python2.7/dist-packages/gunicorn/workers/sync.py”, line 126, in handle_request
respiter = self.wsgi(environ, resp.start_response)
File “lib/webnotes/middlewares.py”, line 12, in call
return super(StaticDataMiddleware, self).call(environ, start_response)
File “/usr/local/lib/python2.7/dist-packages/werkzeug/wsgi.py”, line 579, in call
return self.app(environ, start_response)
File “/usr/local/lib/python2.7/dist-packages/werkzeug/local.py”, line 224, in application
return ClosingIterator(app(environ, start_response), self.cleanup)
File “/usr/local/lib/python2.7/dist-packages/werkzeug/wrappers.py”, line 285, in application
return f(*args[:-2] + (request,))(*args[-2:])
File “/home/erpnext/erpnext/lib/webnotes/app.py”, line 57, in application
webnotes.webutils.render(webnotes.request.path[1:])
File “lib/webnotes/webutils.py”, line 25, in render
html = render_page(“login”)
File “lib/webnotes/webutils.py”, line 46, in render_page
html = build_page(page_name)
File “lib/webnotes/webutils.py”, line 72, in build_page
sitemap_options = webnotes.doc(“Website Sitemap”, page_name).fields
File “lib/webnotes/init.py”, line 397, in doc
return Document(doctype, name, fielddata)
File “lib/webnotes/model/doc.py”, line 82, in init
self._loadfromdb(doctype, name)
File “lib/webnotes/model/doc.py”, line 141, in _loadfromdb
raise webnotes.DoesNotExistError, ‘[WNF] %s %s does not exist’ % (self.doctype, self.name)
DoesNotExistError: [WNF] Website Sitemap login does not exist
2014-10-19 16:20:30 [1302] [ERROR] Error handling request
Traceback (most recent call last):
File “/usr/lib/python2.7/dist-packages/gunicorn/workers/sync.py”, line 126, in handle_request
respiter = self.wsgi(environ, resp.start_response)
File “lib/webnotes/middlewares.py”, line 12, in call
return super(StaticDataMiddleware, self).call(environ, start_response)
File “/usr/local/lib/python2.7/dist-packages/werkzeug/wsgi.py”, line 579, in call
return self.app(environ, start_response)
File “/usr/local/lib/python2.7/dist-packages/werkzeug/local.py”, line 224, in application
return ClosingIterator(app(environ, start_response), self.cleanup)
File “/usr/local/lib/python2.7/dist-packages/werkzeug/wrappers.py”, line 285, in application
return f(*args[:-2] + (request,))(*args[-2:])
File “/home/erpnext/erpnext/lib/webnotes/app.py”, line 57, in application
webnotes.webutils.render(webnotes.request.path[1:])
File “lib/webnotes/webutils.py”, line 25, in render
html = render_page(“login”)
File “lib/webnotes/webutils.py”, line 46, in render_page
html = build_page(page_name)
File “lib/webnotes/webutils.py”, line 72, in build_page
sitemap_options = webnotes.doc(“Website Sitemap”, page_name).fields
File “lib/webnotes/init.py”, line 397, in doc
return Document(doctype, name, fielddata)
File “lib/webnotes/model/doc.py”, line 82, in init
self._loadfromdb(doctype, name)
File “lib/webnotes/model/doc.py”, line 141, in _loadfromdb
raise webnotes.DoesNotExistError, ‘[WNF] %s %s does not exist’ % (self.doctype, self.name)
DoesNotExistError: [WNF] Website Sitemap login does not exist
2014-10-19 16:21:10 [1301] [ERROR] Error handling request
Traceback (most recent call last):
File “/usr/lib/python2.7/dist-packages/gunicorn/workers/sync.py”, line 126, in handle_request
respiter = self.wsgi(environ, resp.start_response)
File “lib/webnotes/middlewares.py”, line 12, in call
return super(StaticDataMiddleware, self).call(environ, start_response)
File “/usr/local/lib/python2.7/dist-packages/werkzeug/wsgi.py”, line 579, in call
return self.app(environ, start_response)
File “/usr/local/lib/python2.7/dist-packages/werkzeug/local.py”, line 224, in application
return ClosingIterator(app(environ, start_response), self.cleanup)
File “/usr/local/lib/python2.7/dist-packages/werkzeug/wrappers.py”, line 285, in application
return f(*args[:-2] + (request,))(*args[-2:])
File “/home/erpnext/erpnext/lib/webnotes/app.py”, line 57, in application
webnotes.webutils.render(webnotes.request.path[1:])
File “lib/webnotes/webutils.py”, line 25, in render
html = render_page(“login”)
File “lib/webnotes/webutils.py”, line 46, in render_page
html = build_page(page_name)
File “lib/webnotes/webutils.py”, line 72, in build_page
sitemap_options = webnotes.doc(“Website Sitemap”, page_name).fields
File “lib/webnotes/init.py”, line 397, in doc
return Document(doctype, name, fielddata)
File “lib/webnotes/model/doc.py”, line 82, in init
self._loadfromdb(doctype, name)
File “lib/webnotes/model/doc.py”, line 141, in _loadfromdb
raise webnotes.DoesNotExistError, ‘[WNF] %s %s does not exist’ % (self.doctype, self.name)
DoesNotExistError: [WNF] Website Sitemap login does not exist

I don’t know what that is but I’m sure it’s why the server does not start automatically on boot

were you able to fix 'tabWebsite Route` doesn’t exist?

Also, what is the output of

supervisorctl status

?
I think you’ve not removed the supervisor config file (/etc/supervisor.d/erpnext.conf)

I created a database table 'tabWebsite Route` for that, giving just one column, name varchar(255).

supervisorctl status gives
frappe:frappe-web RUNNING pid 2349, uptime 0:00:02
frappe:frappe-worker RUNNING pid 1335, uptime 0:01:27
frappe:frappe-workerbeat RUNNING pid 1343, uptime 0:01:27
gunicorn RUNNING pid 1357, uptime 0:01:27

And there’s no file /etc/supervisor.d/erpnext.conf in that location.

okay, the line that says ‘gunicorn’ is running the server from old code base and you’ll have to get rid of it. What is the output of ?

ls /etc/supervisor/conf.d/

frappe.conf gunicorn.conf

EDIT: OK so I removed gunicorn.conf and the server seems to be starting on its own. Still rebooting to test

OK so a big, great thank you to everyone who helped. I now have the server working and a successful upgrade. Thank you guys. You’ve a lifetime ERPNext evangelist here in Ghana :smile:

2 Likes