etherpad_mypads_ynh
etherpad_mypads_ynh copied to clipboard
Etherpad crash after last upgrade - loop restarting
Describe the bug
After last upgrade, etherpad_mypads is starting and exiting continuously. Got the problem on 2 different servers.
Context
- Hardware: Old laptop or computer
- YunoHost version: 11.1.21.4
- I have access to my server: Through SSH and through the webadmin and direct access via keyboard / screen | ...
- Are you in a special context or did you perform some particular tweaking on your YunoHost instance?: no
- Using, or trying to install package version/branch: upgrade to etherpad_mypads 1.9.1-ynh1
Steps to reproduce
Upgrade etherpad_mypas in the webadmin
Expected behavior
Etherpad_mypads working after upgrade
Logs
[2023-07-03 23:19:17.648] [ERROR] server - Error: Command exited with code 1: npm ls --long --json --depth=0 --no-production
at exports (/var/www/etherpad_mypads/src/node/utils/run_cmd.js:119:25)
at Object.exports.getPackages (/var/www/etherpad_mypads/src/static/js/pluginfw/plugins.js:115:48)
at Object.exports.update (/var/www/etherpad_mypads/src/static/js/pluginfw/plugins.js:86:34)
at Object.exports.start (/var/www/etherpad_mypads/src/node/server.js:143:19)
at processTicksAndRejections (internal/process/task_queues.js:95:5)
[2023-07-03 23:19:17.648] [INFO] server - Exiting...
[2023-07-03 23:19:17.648] [INFO] server - Waiting for Node.js to exit...
[2023-07-03 23:19:22.649] [ERROR] server - Something that should have been cleaned up during the shutdown hook (such as a timer, worker thread, or open connection) is preventing Node.js from exiting
[2023-07-03 23:19:22.649] [ERROR] server - Enable `dumpOnUncleanExit` setting to get a dump of objects preventing a clean exit
[2023-07-03 23:19:22.650] [ERROR] server - Forcing an unclean exit...
[2023-07-03 23:19:23.104] [INFO] settings - All relative paths will be interpreted relative to the identified Etherpad base dir: /var/www/etherpad_mypads
[2023-07-03 23:19:23.122] [INFO] settings - settings loaded from: /var/www/etherpad_mypads/settings.json
[2023-07-03 23:19:23.123] [INFO] settings - credentials loaded from: /var/www/etherpad_mypads/credentials.json
[2023-07-03 23:19:23.124] [INFO] settings - Using skin "colibris" in dir: /var/www/etherpad_mypads/src/static/skins/colibris
[2023-07-03 23:19:23.124] [INFO] settings - Session key loaded from: /var/www/etherpad_mypads/SESSIONKEY.txt
[2023-07-03 23:19:23.125] [INFO] settings - Random string used for versioning assets: aa1e719a
[2023-07-03 23:19:23.371] [INFO] server - Starting Etherpad...
[2023-07-03 23:19:23.471] [INFO] plugins - Running npm to get a list of installed plugins...
[2023-07-03 23:19:23.577] [INFO] plugins - npm --version: 6.14.16
[2023-07-03 23:19:27.959] [ERROR] runCmd|npm - npm ERR! peer dep missing: eslint@^2 || ^3 || ^4 || ^5 || ^6 || ^7.2.0 || ^8, required by [email protected]
[2023-07-03 23:19:27.979] [ERROR] server - Error occurred while starting Etherpad
[2023-07-03 23:19:27.980] [ERROR] server - Metrics at time of fatal error:
{
"httpStartTime": 0,
"memoryUsage": 68923392,
"memoryUsageHeap": 13537056,
"ueberdb_lockAwaits": 0,
"ueberdb_lockAcquires": 0,
"ueberdb_lockReleases": 0,
"ueberdb_reads": 0,
"ueberdb_readsFailed": 0,
"ueberdb_readsFinished": 0,
"ueberdb_readsFromCache": 0,
"ueberdb_readsFromDb": 0,
"ueberdb_readsFromDbFailed": 0,
"ueberdb_readsFromDbFinished": 0,
"ueberdb_writes": 0,
"ueberdb_writesFailed": 0,
"ueberdb_writesFinished": 0,
"ueberdb_writesObsoleted": 0,
"ueberdb_writesToDb": 0,
"ueberdb_writesToDbFailed": 0,
"ueberdb_writesToDbFinished": 0,
"ueberdb_writesToDbRetried": 0
}
[2023-07-03 23:19:27.980] [ERROR] server - Error: Command exited with code 1: npm ls --long --json --depth=0 --no-production
at exports (/var/www/etherpad_mypads/src/node/utils/run_cmd.js:119:25)
at Object.exports.getPackages (/var/www/etherpad_mypads/src/static/js/pluginfw/plugins.js:115:48)
at Object.exports.update (/var/www/etherpad_mypads/src/static/js/pluginfw/plugins.js:86:34)
at Object.exports.start (/var/www/etherpad_mypads/src/node/server.js:143:19)
at processTicksAndRejections (internal/process/task_queues.js:95:5)
same here, on same versions. I'll keep an eye on this issue, hope it's easy to fix. I can provide logs and tests if needed.
+ I mistakenly removed the auto_etherpad backup that is made by the upgrade script from previous version (by forcing a reinstall of same app version) soooo... anyone know how to reinstall a previous version AND back-up the data ? :grin:
same here, only on a raspberry Pi 4. On another server I have done the upgrade without issues, but perhaps it was with a system yunohost a bit older than the last stable...
we have a problem on this file
cat -n /var/www/etherpad_mypads/src/static/js/pluginfw/plugins.js
1 'use strict';
2
3 const fs = require('fs').promises;
4 const hooks = require('./hooks');
5 const log4js = require('log4js');
6 const path = require('path');
7 const runCmd = require('../../../node/utils/run_cmd');
8 const tsort = require('./tsort');
9 const pluginUtils = require('./shared');
10 const defs = require('./plugin_defs');
11
12 const logger = log4js.getLogger('plugins');
13
14 // Log the version of npm at startup.
15 (async () => {
16 try {
17 const version = await runCmd(['npm', '--version'], {stdio: [null, 'string']});
18 logger.info(`npm --version: ${version}`);
19 } catch (err) {
20 logger.error(`Failed to get npm version: ${err.stack || err}`);
21 // This isn't a fatal error so don't re-throw.
22 }
23 })();
24
25 exports.prefix = 'ep_';
26
27 exports.formatPlugins = () => Object.keys(defs.plugins).join(', ');
28
29 exports.formatParts = () => defs.parts.map((part) => part.full_name).join('\n');
30
31 exports.formatHooks = (hookSetName, html) => {
32 let hooks = new Map();
33 for (const [pluginName, def] of Object.entries(defs.plugins)) {
34 for (const part of def.parts) {
35 for (const [hookName, hookFnName] of Object.entries(part[hookSetName] || {})) {
36 let hookEntry = hooks.get(hookName);
37 if (!hookEntry) {
38 hookEntry = new Map();
39 hooks.set(hookName, hookEntry);
40 }
41 let pluginEntry = hookEntry.get(pluginName);
42 if (!pluginEntry) {
43 pluginEntry = new Map();
44 hookEntry.set(pluginName, pluginEntry);
45 }
46 pluginEntry.set(part.name, hookFnName);
47 }
48 }
49 }
50 const lines = [];
51 const sortStringKeys = (a, b) => String(a[0]).localeCompare(b[0]);
52 if (html) lines.push('<dl>');
53 hooks = new Map([...hooks].sort(sortStringKeys));
54 for (const [hookName, hookEntry] of hooks) {
55 lines.push(html ? ` <dt>${hookName}:</dt><dd><dl>` : ` ${hookName}:`);
56 const sortedHookEntry = new Map([...hookEntry].sort(sortStringKeys));
57 hooks.set(hookName, sortedHookEntry);
58 for (const [pluginName, pluginEntry] of sortedHookEntry) {
59 lines.push(html ? ` <dt>${pluginName}:</dt><dd><dl>` : ` ${pluginName}:`);
60 const sortedPluginEntry = new Map([...pluginEntry].sort(sortStringKeys));
61 sortedHookEntry.set(pluginName, sortedPluginEntry);
62 for (const [partName, hookFnName] of sortedPluginEntry) {
63 lines.push(html
64 ? ` <dt>${partName}:</dt><dd>${hookFnName}</dd>`
65 : ` ${partName}: ${hookFnName}`);
66 }
67 if (html) lines.push(' </dl></dd>');
68 }
69 if (html) lines.push(' </dl></dd>');
70 }
71 if (html) lines.push('</dl>');
72 return lines.join('\n');
73 };
74
75 exports.pathNormalization = (part, hookFnName, hookName) => {
76 const tmp = hookFnName.split(':'); // hookFnName might be something like 'C:\\foo.js:myFunc'.
77 // If there is a single colon assume it's 'filename:funcname' not 'C:\\filename'.
78 const functionName = (tmp.length > 1 ? tmp.pop() : null) || hookName;
79 const moduleName = tmp.join(':') || part.plugin;
80 const packageDir = path.dirname(defs.plugins[part.plugin].package.path);
81 const fileName = path.join(packageDir, moduleName);
82 return `${fileName}:${functionName}`;
83 };
84
85 exports.update = async () => {
86 const packages = await exports.getPackages();
87 const parts = {}; // Key is full name. sortParts converts this into a topologically sorted array.
88 const plugins = {};
89
90 // Load plugin metadata ep.json
91 await Promise.all(Object.keys(packages).map(async (pluginName) => {
92 logger.info(`Loading plugin ${pluginName}...`);
93 await loadPlugin(packages, pluginName, plugins, parts);
94 }));
95 logger.info(`Loaded ${Object.keys(packages).length} plugins`);
96
97 defs.plugins = plugins;
98 defs.parts = sortParts(parts);
99 defs.hooks = pluginUtils.extractHooks(defs.parts, 'hooks', exports.pathNormalization);
100 defs.loaded = true;
101 await Promise.all(Object.keys(defs.plugins).map(async (p) => {
102 const logger = log4js.getLogger(`plugin:${p}`);
103 await hooks.aCallAll(`init_${p}`, {logger});
104 }));
105 };
106
107 exports.getPackages = async () => {
108 logger.info('Running npm to get a list of installed plugins...');
109 // Notes:
110 // * Do not pass `--prod` otherwise `npm ls` will fail if there is no `package.json`.
111 // * The `--no-production` flag is required (or the `NODE_ENV` environment variable must be
112 // unset or set to `development`) because otherwise `npm ls` will not mention any packages
113 // that are not included in `package.json` (which is expected to not exist).
114 const cmd = ['npm', 'ls', '--long', '--json', '--depth=0', '--no-production'];
115 const {dependencies = {}} = JSON.parse(await runCmd(cmd, {stdio: [null, 'string']}));
116 await Promise.all(Object.entries(dependencies).map(async ([pkg, info]) => {
117 if (!pkg.startsWith(exports.prefix)) {
118 delete dependencies[pkg];
119 return;
120 }
121 info.realPath = await fs.realpath(info.path);
122 }));
123 return dependencies;
124 };
125
126 const loadPlugin = async (packages, pluginName, plugins, parts) => {
127 const pluginPath = path.resolve(packages[pluginName].path, 'ep.json');
128 try {
129 const data = await fs.readFile(pluginPath);
130 try {
131 const plugin = JSON.parse(data);
132 plugin.package = packages[pluginName];
133 plugins[pluginName] = plugin;
134 for (const part of plugin.parts) {
135 part.plugin = pluginName;
136 part.full_name = `${pluginName}/${part.name}`;
137 parts[part.full_name] = part;
138 }
139 } catch (err) {
140 logger.error(`Unable to parse plugin definition file ${pluginPath}: ${err.stack || err}`);
141 }
142 } catch (err) {
143 logger.error(`Unable to load plugin definition file ${pluginPath}: ${err.stack || err}`);
144 }
145 };
146
147 const partsToParentChildList = (parts) => {
148 const res = [];
149 for (const name of Object.keys(parts)) {
150 for (const childName of parts[name].post || []) {
151 res.push([name, childName]);
152 }
153 for (const parentName of parts[name].pre || []) {
154 res.push([parentName, name]);
155 }
156 if (!parts[name].pre && !parts[name].post) {
157 res.push([name, `:${name}`]); // Include apps with no dependency info
158 }
159 }
160 return res;
161 };
162
163 // Used only in Node, so no need for _
164 const sortParts = (parts) => tsort(partsToParentChildList(parts))
165 .filter((name) => parts[name] !== undefined)
166 .map((name) => parts[name]);
Perhaps one of the plugins is no more supported ??
It seems breaking here
107 exports.getPackages = async () => {
108 logger.info('Running npm to get a list of installed plugins...');
109 // Notes:
110 // * Do not pass `--prod` otherwise `npm ls` will fail if there is no `package.json`.
111 // * The `--no-production` flag is required (or the `NODE_ENV` environment variable must be
112 // unset or set to `development`) because otherwise `npm ls` will not mention any packages
113 // that are not included in `package.json` (which is expected to not exist).
114 const cmd = ['npm', 'ls', '--long', '--json', '--depth=0', '--no-production'];
115 const {dependencies = {}} = JSON.parse(await runCmd(cmd, {stdio: [null, 'string']}));
116 await Promise.all(Object.entries(dependencies).map(async ([pkg, info]) => {
117 if (!pkg.startsWith(exports.prefix)) {
118 delete dependencies[pkg];
119 return;
120 }
121 info.realPath = await fs.realpath(info.path);
122 }));
123 return dependencies;
124 };
Do you have an extra plugins installed? (plugins not installed with the app)
Same problem for me, I don't think I have installed extra plug-in : `
Greffons installés
align Etherpad plugin to set left, center, right, or full justification for a paragraph 0.3.53 author_hover Adds author names to span titles (shows on hover), works as authors change their name. Hover includes author color and fast switching between author spans. Hat tip to Martyn York for the initial work on this. 0.3.37 comments_page Adds comments on sidebar and link it to the text. For no-skin use ep_page_view. 1.0.5 countable Displays paragraphs, sentences, words and characters counts. 0.0.13 delete_empty_pads Delete pads which were never edited [DO NOT UPGRADE IF Etherpad < 1.8.0] 0.0.9 font_color Apply colors to fonts 0.0.63 font_size Apply sizes to fonts 0.4.44 headings2 Adds heading support to Etherpad Lite. Includes improved suppot for export, i18n etc. 0.2.44 markdown Edit and Export as Markdown in Etherpad 0.1.50 mypads Groups and private pads for etherpad 1.7.24 spellcheck Add support to do 'Spell checking', with a toggle on/off option in Settings 0.0.43 subscript_and_superscript Add support for different Fonts 0.2.47 table_of_contents View a table of contents for your pad 0.3.42`
It happens again also on another server... here the last logs of the upgrade
Info: [#################+..] > Starting a systemd service...
Warning: (this may take some time)
Warning: The service etherpad_mypads didn't fully executed the action restart before the timeout.
Warning: Please find here an extract of the end of the log of the service etherpad_mypads:
Warning: Jul 25 23:49:49 systemd[1]: etherpad_mypads.service: Failed with result 'exit-code'.
Warning: Jul 25 23:49:49 systemd[1]: etherpad_mypads.service: Consumed 13.316s CPU time.
Warning: Jul 25 23:49:50 systemd[1]: etherpad_mypads.service: Scheduled restart job, restart counter is at 3.
Warning: Jul 25 23:49:50 systemd[1]: Stopped Etherpad-lite: the collaborative editor..
Warning: Jul 25 23:49:50 systemd[1]: etherpad_mypads.service: Consumed 13.316s CPU time.
Warning: Jul 25 23:49:50 systemd[1]: Started Etherpad-lite: the collaborative editor..
Warning: Jul 25 23:50:05 systemd[1]: etherpad_mypads.service: Main process exited, code=exited, status=1/FAILURE
Warning: Jul 25 23:50:05 systemd[1]: etherpad_mypads.service: Failed with result 'exit-code'.
Warning: Jul 25 23:50:05 systemd[1]: etherpad_mypads.service: Consumed 14.133s CPU time.
Warning: Jul 25 23:50:06 systemd[1]: etherpad_mypads.service: Scheduled restart job, restart counter is at 4.
Warning: Jul 25 23:50:06 systemd[1]: Stopped Etherpad-lite: the collaborative editor..
Warning: Jul 25 23:50:06 systemd[1]: etherpad_mypads.service: Consumed 14.133s CPU time.
Warning: Jul 25 23:50:06 systemd[1]: Started Etherpad-lite: the collaborative editor..
Warning: Jul 25 23:50:21 systemd[1]: etherpad_mypads.service: Main process exited, code=exited, status=1/FAILURE
Warning: Jul 25 23:50:21 systemd[1]: etherpad_mypads.service: Failed with result 'exit-code'.
Warning: Jul 25 23:50:21 systemd[1]: etherpad_mypads.service: Consumed 13.304s CPU time.
Warning: Jul 25 23:50:21 systemd[1]: etherpad_mypads.service: Scheduled restart job, restart counter is at 5.
Warning: Jul 25 23:50:21 systemd[1]: Stopped Etherpad-lite: the collaborative editor..
Warning: Jul 25 23:50:21 systemd[1]: etherpad_mypads.service: Consumed 13.304s CPU time.
Warning: Jul 25 23:50:21 systemd[1]: Started Etherpad-lite: the collaborative editor
Warning: \-\-\-
Warning: "ueberdb_readsFromDb": 0,
Warning: "ueberdb_readsFromDbFailed": 0,
Warning: "ueberdb_readsFromDbFinished": 0,
Warning: "ueberdb_writes": 0,
Warning: "ueberdb_writesFailed": 0,
Warning: "ueberdb_writesFinished": 0,
Warning: "ueberdb_writesObsoleted": 0,
Warning: "ueberdb_writesToDb": 0,
Warning: "ueberdb_writesToDbFailed": 0,
Warning: "ueberdb_writesToDbFinished": 0,
Warning: "ueberdb_writesToDbRetried": 0
Warning: }
Warning: [2023-07-25 23:50:32.429] [ERROR] server - Error: Command exited with code 1: npm ls --long --json --depth=0 --no-production
Warning: at exports (/var/www/etherpad_mypads/src/node/utils/run_cmd.js:119:25)
Warning: at Object.exports.getPackages (/var/www/etherpad_mypads/src/static/js/pluginfw/plugins.js:115:48)
Warning: at Object.exports.update (/var/www/etherpad_mypads/src/static/js/pluginfw/plugins.js:86:34)
Warning: at Object.exports.start (/var/www/etherpad_mypads/src/node/server.js:143:19)
Warning: at processTicksAndRejections (internal/process/task_queues.js:95:5)
Warning: [2023-07-25 23:50:32.429] [INFO] server - Exiting...
Warning: [2023-07-25 23:50:32.429] [INFO] server - Waiting for Node.js to exit...
Info: [##################+.] > Reconfiguring Fail2Ban...
Info: The service fail2ban has correctly executed the action reload-or-restart.
Info: [###################.] > Disabling maintenance mode...
Info: [####################] > Upgrade of etherpad_mypads completed
Success! etherpad_mypads upgraded
Success! Upgrade complet
but it is broken and just give me a page with nginx. I come back to the older version...
Do you have an extra plugins installed? (plugins not installed with the app)
No extra plugins installed in my case, but in etherpad's admin interface updates are proposed for 2 plugins :
To workaround the issue:
# yunohost app shell etherpad_mypads
$ npm install eslint
To workaround the issue:
# yunohost app shell etherpad_mypads $ npm install eslint
Interesting, how did you work that out ? I'm not able to test it right now, but I'll do it soon !
Hi all. My Etherpad has been working healthy for past year. But my Etherpad didn't launch any more after the last upgrade, same versions too.
I remember that I saw "fatal error" message on my log during the upgrade and upgrade never ended on the "System update" web interface, so I just closed the page after 1 hour.
Then I rebooted my yunohost and tried to start Etherpad from the https://domain/yunohost/sso/ app launcher. The app launcher didn't launch the up at all, doesn't do anything after clicking the "Et Etherpad". I went to check if others are encountering same issue on yunohost forum, tag/etherpad_mypads. There are reports but there was no solution given. So I came here on github and found the @fflorent's workaround command.
I couldn't be patient to wait for someone to test the @fflorent's command. Considering the fact that my machine also showed "npm ERR! peer dep missing: eslint" in the error message, I decided to run the suggested command on my machine to see what happens.
This is what my screen showed when I run the command.
etherpad_mypads@xxx:~$ npm install eslint npm WARN deprecated @npmcli/[email protected]: This functionality has been moved t o @npmcli/fs
[email protected] install /var/www/etherpad_mypads/src/node_modules/sqlite3 node-pre-gyp install --fallback-to-build
sh: 1: node-pre-gyp: not found
npm WARN saveError ENOENT: no such file or directory, open '/var/www/etherpad_my pads/package.json'
npm notice created a lockfile as package-lock.json. You should commit this file.
npm WARN enoent ENOENT: no such file or directory, open '/var/www/etherpad_mypad s/package.json'
npm WARN etherpad_mypads No description
npm WARN etherpad_mypads No repository field.
npm WARN etherpad_mypads No README data
npm WARN etherpad_mypads No license field.
npm WARN optional SKIPPING OPTIONAL DEPENDENCY: [email protected] (src/node_modules/ sqlite3):
npm WARN optional SKIPPING OPTIONAL DEPENDENCY: [email protected] install: node-pre -gyp install --fallback-to-build
npm WARN optional SKIPPING OPTIONAL DEPENDENCY: spawn ENOENT
- [email protected] added 64 packages from 37 contributors in 37.319s
248 packages are looking for funding
run npm fund
for details
etherpad_mypads@xxx:~$
After installing the npm eslint, Etherpad works normally again on my yunohost!!!
Thanks to @fflorent for sharing his knowledge and experience when people needs the solution!!!
Update:
I spent past 6 hours to test Etherpad with multiple users while working on a single pad after I made my report that my Etherpad worked again.
After 6 hours of test drving of Etherpad, I have to add info here that it seems that my Etherpad is not functioning fully well to me on my machine comparing with before upgrading.
Immediately after installing the npm eslint, my Etherpad was launched successfully. Then I saw myPad screen and I typed my own preferred link for a new pad and the new pad was generated.
After working on a single pad with multiple users, I closed the pad.
After I closed the pad, new session of my Etherpad doesn’t launch anymore.
I haven’t rebooted yunohost yet to see if Etherpad runs or not since I am hurrying to write this up and share as an update.
By clicking “Et Etherpad” on the app menu, https://domain/yunohost/sso/, rather than Etherpad being launched, it comes back to https://domain/yunohost/sso/.
I can’t tell if Etherpad is working fully fine or not in my capacity. So in the meantime, I will be watching this issue #186 for others to come up with comments.
Thanks!