From a40b581ee97f644f1d42f73fcbb72ad08d7c058b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=D0=92=D1=81=D0=B5=D0=B2=D0=BE=D0=BB=D0=BE=D0=B4?= Date: Sat, 2 Mar 2024 16:14:09 +0300 Subject: [PATCH 1/8] handle usage stats --- api/package.json | 5 +++-- api/src/job.js | 57 ++++++++++++++++++++++++++++++++++++++++++++++-- 2 files changed, 58 insertions(+), 4 deletions(-) diff --git a/api/package.json b/api/package.json index 0b91c01..df590aa 100644 --- a/api/package.json +++ b/api/package.json @@ -14,7 +14,8 @@ "node-fetch": "^2.6.1", "semver": "^7.3.4", "uuid": "^8.3.2", - "waitpid": "git+https://github.com/HexF/node-waitpid.git" + "waitpid": "git+https://github.com/HexF/node-waitpid.git", + "pidusage": "^3.0.2" }, "license": "MIT" -} +} \ No newline at end of file diff --git a/api/src/job.js b/api/src/job.js index a2641f9..6f137ce 100644 --- a/api/src/job.js +++ b/api/src/job.js @@ -8,6 +8,7 @@ const globals = require('./globals'); const fs = require('fs/promises'); const fss = require('fs'); const wait_pid = require('waitpid'); +const pidusage = require('pidusage'); const job_states = { READY: Symbol('Ready to be primed'), @@ -136,6 +137,32 @@ class Job { this.logger.debug('Destroyed processes writables'); } + get_stats(pid) { + // https://www.npmjs.com/package/pidusage + return new Promise((resolve, reject) => { + pidusage(pid, { + usePs: true, + }, (err, stat) => { + if (err) { + this.logger.error(`Error getting process stats:`, err); + reject(err); + } + + let res = { + 'cpu': stat.cpu, + 'memory': stat.memory, + 'ctime': stat.ctime, + 'elapsed': stat.elapsed, + 'timestamp': stat.timestamp, + }; + + this.logger.debug(`Got stats:`, res); + + resolve(res); + }); + }); + } + async safe_call(file, args, timeout, memory_limit, event_bus = null) { return new Promise((resolve, reject) => { const nonetwork = config.disable_networking ? ['nosocket'] : []; @@ -171,6 +198,7 @@ class Job { var stdout = ''; var stderr = ''; var output = ''; + var stats = []; const proc = cp.spawn(proc_call[0], proc_call.splice(1), { env: { @@ -186,6 +214,10 @@ class Job { this.#active_parent_processes.push(proc); + this.get_stats(proc.pid).then(stat => { + stats.push(stat); + }); + if (event_bus === null) { proc.stdin.write(this.stdin); proc.stdin.end(); @@ -203,6 +235,9 @@ class Job { const kill_timeout = (timeout >= 0 && set_timeout(async _ => { + this.get_stats(proc.pid).then(stat => { + stats.push(stat); + }); this.logger.info(`Timeout exceeded timeout=${timeout}`); try { process.kill(proc.pid, 'SIGKILL'); @@ -237,6 +272,10 @@ class Job { stderr += data; output += data; } + + this.get_stats(proc.pid).then(stat => { + stats.push(stat); + }); }); proc.stdout.on('data', async data => { @@ -258,6 +297,10 @@ class Job { stdout += data; output += data; } + + this.get_stats(proc.pid).then(stat => { + stats.push(stat); + }); }); proc.on('exit', () => this.exit_cleanup()); @@ -265,14 +308,24 @@ class Job { proc.on('close', (code, signal) => { this.close_cleanup(); - resolve({ stdout, stderr, code, signal, output }); + if (stats.length !== 0) { + stats = stats[stats.length - 1]; + } + + this.logger.debug(`Last stats:`, stats); + resolve({ stdout, stderr, code, signal, output, stats }); }); proc.on('error', err => { this.exit_cleanup(); this.close_cleanup(); - reject({ error: err, stdout, stderr, output }); + if (stats.length !== 0) { + stats = stats[stats.length - 1]; + } + + this.logger.debug(`Last stats:`, stats); + reject({ error: err, stdout, stderr, output, stats }); }); }); } From 86a88d44b7d0780c9ede5e90ba299030fbd71667 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=D0=92=D1=81=D0=B5=D0=B2=D0=BE=D0=BB=D0=BE=D0=B4?= Date: Sat, 2 Mar 2024 20:16:00 +0300 Subject: [PATCH 2/8] Fix crash --- api/src/job.js | 27 +++++++++++++-------------- 1 file changed, 13 insertions(+), 14 deletions(-) diff --git a/api/src/job.js b/api/src/job.js index 6f137ce..8e8d022 100644 --- a/api/src/job.js +++ b/api/src/job.js @@ -144,21 +144,20 @@ class Job { usePs: true, }, (err, stat) => { if (err) { - this.logger.error(`Error getting process stats:`, err); - reject(err); + this.logger.debug(`Got error while getting stats:`, err); + } else { + let res = { + 'cpu': stat.cpu, + 'memory': stat.memory, + 'ctime': stat.ctime, + 'elapsed': stat.elapsed, + 'timestamp': stat.timestamp, + }; + + this.logger.debug(`Got stats:`, res); + + resolve(res); } - - let res = { - 'cpu': stat.cpu, - 'memory': stat.memory, - 'ctime': stat.ctime, - 'elapsed': stat.elapsed, - 'timestamp': stat.timestamp, - }; - - this.logger.debug(`Got stats:`, res); - - resolve(res); }); }); } From 25737baf821e397be9d9494fd58074561f50c941 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=D0=92=D1=81=D0=B5=D0=B2=D0=BE=D0=BB=D0=BE=D0=B4?= Date: Sun, 3 Mar 2024 20:25:40 +0300 Subject: [PATCH 3/8] Calculate exec time in code --- api/src/job.js | 12 ++++++++++-- docker-compose.dev.yaml | 7 ++++--- 2 files changed, 14 insertions(+), 5 deletions(-) diff --git a/api/src/job.js b/api/src/job.js index 8e8d022..5af355d 100644 --- a/api/src/job.js +++ b/api/src/job.js @@ -199,6 +199,8 @@ class Job { var output = ''; var stats = []; + var start_time = new Date().getTime(); + const proc = cp.spawn(proc_call[0], proc_call.splice(1), { env: { ...this.runtime.env_vars, @@ -311,8 +313,11 @@ class Job { stats = stats[stats.length - 1]; } + var end_time = new Date().getTime(); + var exec_time = end_time - start_time; + this.logger.debug(`Last stats:`, stats); - resolve({ stdout, stderr, code, signal, output, stats }); + resolve({ stdout, stderr, code, signal, output, stats, exec_time }); }); proc.on('error', err => { @@ -323,8 +328,11 @@ class Job { stats = stats[stats.length - 1]; } + var end_time = new Date().getTime(); + var exec_time = end_time - start_time; + this.logger.debug(`Last stats:`, stats); - reject({ error: err, stdout, stderr, output, stats }); + reject({ error: err, stdout, stderr, output, stats, exec_time }); }); }); } diff --git a/docker-compose.dev.yaml b/docker-compose.dev.yaml index 8a0d385..3eb89e9 100644 --- a/docker-compose.dev.yaml +++ b/docker-compose.dev.yaml @@ -12,13 +12,14 @@ services: volumes: - ./data/piston/packages:/piston/packages environment: - - PISTON_REPO_URL=http://repo:8000/index + - PISTON_REPO_URL=https://github.com/engineer-man/piston/releases/download/pkgs/index tmpfs: - /piston/jobs:exec,uid=1000,gid=1000,mode=711 - repo: # Local testing of packages + repo: + # Local testing of packages build: repo container_name: piston_repo - command: ['--no-build'] # Don't build anything + command: [ '--no-build' ] # Don't build anything volumes: - .:/piston From 32f082fab72280010d3550328546a17e60c40286 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=D0=92=D1=81=D0=B5=D0=B2=D0=BE=D0=BB=D0=BE=D0=B4?= Date: Tue, 5 Mar 2024 20:22:26 +0300 Subject: [PATCH 4/8] Add try catch on get_stats in timeout killer --- api/src/job.js | 11 ++++++++--- 1 file changed, 8 insertions(+), 3 deletions(-) diff --git a/api/src/job.js b/api/src/job.js index 5af355d..9709d92 100644 --- a/api/src/job.js +++ b/api/src/job.js @@ -236,9 +236,14 @@ class Job { const kill_timeout = (timeout >= 0 && set_timeout(async _ => { - this.get_stats(proc.pid).then(stat => { - stats.push(stat); - }); + try { + this.get_stats(proc.pid).then(stat => { + stats.push(stat); + }); + } catch (e) { + this.logger.debug(`Got error while getting stats:`, e); + } + this.logger.info(`Timeout exceeded timeout=${timeout}`); try { process.kill(proc.pid, 'SIGKILL'); From bf50ab406b060c1df6921c851d6b5bd9f4a447d0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=D0=92=D1=81=D0=B5=D0=B2=D0=BE=D0=BB=D0=BE=D0=B4?= Date: Sat, 9 Mar 2024 23:06:15 +0300 Subject: [PATCH 5/8] Move from pid usage to `time` --- TODO.md | 1 + api/Dockerfile | 6 ++--- api/package.json | 3 +-- api/src/job.js | 70 +++++++++++++----------------------------------- 4 files changed, 23 insertions(+), 57 deletions(-) create mode 100644 TODO.md diff --git a/TODO.md b/TODO.md new file mode 100644 index 0000000..4dfdc47 --- /dev/null +++ b/TODO.md @@ -0,0 +1 @@ +1. add time format line (https://www.man7.org/linux/man-pages/man1/time.1.html#top_of_page) \ No newline at end of file diff --git a/api/Dockerfile b/api/Dockerfile index ec0d2a8..4436fbc 100644 --- a/api/Dockerfile +++ b/api/Dockerfile @@ -4,8 +4,8 @@ ENV DEBIAN_FRONTEND=noninteractive RUN dpkg-reconfigure -p critical dash RUN for i in $(seq 1001 1500); do \ - groupadd -g $i runner$i && \ - useradd -M runner$i -g $i -u $i ; \ + groupadd -g $i runner$i && \ + useradd -M runner$i -g $i -u $i ; \ done RUN apt-get update && \ apt-get install -y libxml2 gnupg tar coreutils util-linux libc6-dev \ @@ -13,7 +13,7 @@ RUN apt-get update && \ libncurses6 libncurses5 libedit-dev libseccomp-dev rename procps python3 \ libreadline-dev libblas-dev liblapack-dev libpcre3-dev libarpack2-dev \ libfftw3-dev libglpk-dev libqhull-dev libqrupdate-dev libsuitesparse-dev \ - libsundials-dev libpcre2-dev && \ + libsundials-dev libpcre2-dev time && \ rm -rf /var/lib/apt/lists/* RUN sed -i '/en_US.UTF-8/s/^# //g' /etc/locale.gen && locale-gen diff --git a/api/package.json b/api/package.json index df590aa..e9a811a 100644 --- a/api/package.json +++ b/api/package.json @@ -14,8 +14,7 @@ "node-fetch": "^2.6.1", "semver": "^7.3.4", "uuid": "^8.3.2", - "waitpid": "git+https://github.com/HexF/node-waitpid.git", - "pidusage": "^3.0.2" + "waitpid": "git+https://github.com/HexF/node-waitpid.git" }, "license": "MIT" } \ No newline at end of file diff --git a/api/src/job.js b/api/src/job.js index 9709d92..7de693c 100644 --- a/api/src/job.js +++ b/api/src/job.js @@ -137,31 +137,6 @@ class Job { this.logger.debug('Destroyed processes writables'); } - get_stats(pid) { - // https://www.npmjs.com/package/pidusage - return new Promise((resolve, reject) => { - pidusage(pid, { - usePs: true, - }, (err, stat) => { - if (err) { - this.logger.debug(`Got error while getting stats:`, err); - } else { - let res = { - 'cpu': stat.cpu, - 'memory': stat.memory, - 'ctime': stat.ctime, - 'elapsed': stat.elapsed, - 'timestamp': stat.timestamp, - }; - - this.logger.debug(`Got stats:`, res); - - resolve(res); - } - }); - }); - } - async safe_call(file, args, timeout, memory_limit, event_bus = null) { return new Promise((resolve, reject) => { const nonetwork = config.disable_networking ? ['nosocket'] : []; @@ -180,6 +155,10 @@ class Job { Math.ceil(timeout / 1000), ]; + const time_format = [ + '-p' + ] + if (memory_limit >= 0) { prlimit.push('--as=' + memory_limit); } @@ -189,6 +168,8 @@ class Job { ...timeout_call, ...prlimit, ...nonetwork, + 'time', + ...time_format, 'bash', file, ...args, @@ -197,7 +178,6 @@ class Job { var stdout = ''; var stderr = ''; var output = ''; - var stats = []; var start_time = new Date().getTime(); @@ -215,10 +195,6 @@ class Job { this.#active_parent_processes.push(proc); - this.get_stats(proc.pid).then(stat => { - stats.push(stat); - }); - if (event_bus === null) { proc.stdin.write(this.stdin); proc.stdin.end(); @@ -236,14 +212,6 @@ class Job { const kill_timeout = (timeout >= 0 && set_timeout(async _ => { - try { - this.get_stats(proc.pid).then(stat => { - stats.push(stat); - }); - } catch (e) { - this.logger.debug(`Got error while getting stats:`, e); - } - this.logger.info(`Timeout exceeded timeout=${timeout}`); try { process.kill(proc.pid, 'SIGKILL'); @@ -278,10 +246,6 @@ class Job { stderr += data; output += data; } - - this.get_stats(proc.pid).then(stat => { - stats.push(stat); - }); }); proc.stdout.on('data', async data => { @@ -303,10 +267,6 @@ class Job { stdout += data; output += data; } - - this.get_stats(proc.pid).then(stat => { - stats.push(stat); - }); }); proc.on('exit', () => this.exit_cleanup()); @@ -314,14 +274,17 @@ class Job { proc.on('close', (code, signal) => { this.close_cleanup(); - if (stats.length !== 0) { - stats = stats[stats.length - 1]; + if (stderr.length > 0) { + var stats = stderr.trim().split('\n').slice(-3).join('\n'); + + stderr = stderr.trim().split('\n').slice(0, -3).join('\n'); + output = output.trim().split('\n').slice(0, -3).join('\n'); } var end_time = new Date().getTime(); var exec_time = end_time - start_time; - this.logger.debug(`Last stats:`, stats); + this.logger.debug(`Stats:`, stats); resolve({ stdout, stderr, code, signal, output, stats, exec_time }); }); @@ -329,14 +292,17 @@ class Job { this.exit_cleanup(); this.close_cleanup(); - if (stats.length !== 0) { - stats = stats[stats.length - 1]; + if (stderr.length > 0) { + var stats = stderr.trim().split('\n').slice(-3).join('\n'); + + stderr = stderr.trim().split('\n').slice(0, -3).join('\n'); + output = output.trim().split('\n').slice(0, -3).join('\n'); } var end_time = new Date().getTime(); var exec_time = end_time - start_time; - this.logger.debug(`Last stats:`, stats); + this.logger.debug(`Stats:`, stats); reject({ error: err, stdout, stderr, output, stats, exec_time }); }); }); From 78d65f799d5e18bbbfc32e71040860f6bb1d6d89 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=D0=92=D1=81=D0=B5=D0=B2=D0=BE=D0=BB=D0=BE=D0=B4?= Date: Sat, 9 Mar 2024 23:17:13 +0300 Subject: [PATCH 6/8] Fix bug --- api/src/job.js | 1 - 1 file changed, 1 deletion(-) diff --git a/api/src/job.js b/api/src/job.js index 7de693c..957ddc6 100644 --- a/api/src/job.js +++ b/api/src/job.js @@ -8,7 +8,6 @@ const globals = require('./globals'); const fs = require('fs/promises'); const fss = require('fs'); const wait_pid = require('waitpid'); -const pidusage = require('pidusage'); const job_states = { READY: Symbol('Ready to be primed'), From bf60f59802eca2943854bc07402f715d037b28c8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=D0=92=D1=81=D0=B5=D0=B2=D0=BE=D0=BB=D0=BE=D0=B4?= Date: Sun, 10 Mar 2024 11:11:24 +0300 Subject: [PATCH 7/8] Add maximum mem usage in stats --- TODO.md | 2 +- api/src/job.js | 15 ++++++++------- 2 files changed, 9 insertions(+), 8 deletions(-) diff --git a/TODO.md b/TODO.md index 4dfdc47..b551121 100644 --- a/TODO.md +++ b/TODO.md @@ -1 +1 @@ -1. add time format line (https://www.man7.org/linux/man-pages/man1/time.1.html#top_of_page) \ No newline at end of file +1. ~~add time format line (https://www.man7.org/linux/man-pages/man1/time.1.html#top_of_page)~~ \ No newline at end of file diff --git a/api/src/job.js b/api/src/job.js index 957ddc6..e038a75 100644 --- a/api/src/job.js +++ b/api/src/job.js @@ -155,7 +155,8 @@ class Job { ]; const time_format = [ - '-p' + '-f', + 'real %es\\nuser %Us\\nsys %Ss\\nmem %MKb', ] if (memory_limit >= 0) { @@ -274,10 +275,10 @@ class Job { this.close_cleanup(); if (stderr.length > 0) { - var stats = stderr.trim().split('\n').slice(-3).join('\n'); + var stats = stderr.trim().split('\n').slice(-4).join('\n'); - stderr = stderr.trim().split('\n').slice(0, -3).join('\n'); - output = output.trim().split('\n').slice(0, -3).join('\n'); + stderr = stderr.trim().split('\n').slice(0, -4).join('\n'); + output = output.trim().split('\n').slice(0, -4).join('\n'); } var end_time = new Date().getTime(); @@ -292,10 +293,10 @@ class Job { this.close_cleanup(); if (stderr.length > 0) { - var stats = stderr.trim().split('\n').slice(-3).join('\n'); + var stats = stderr.trim().split('\n').slice(-4).join('\n'); - stderr = stderr.trim().split('\n').slice(0, -3).join('\n'); - output = output.trim().split('\n').slice(0, -3).join('\n'); + stderr = stderr.trim().split('\n').slice(0, -4).join('\n'); + output = output.trim().split('\n').slice(0, -4).join('\n'); } var end_time = new Date().getTime(); From 4176e70509a469758e269df06b8c5781b44a7517 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=D0=92=D1=81=D0=B5=D0=B2=D0=BE=D0=BB=D0=BE=D0=B4?= Date: Sun, 10 Mar 2024 15:28:59 +0300 Subject: [PATCH 8/8] Convert stats str to JSON object --- api/src/job.js | 28 +++++++++++++++++++++------- 1 file changed, 21 insertions(+), 7 deletions(-) diff --git a/api/src/job.js b/api/src/job.js index e038a75..cc2d236 100644 --- a/api/src/job.js +++ b/api/src/job.js @@ -156,7 +156,9 @@ class Job { const time_format = [ '-f', - 'real %es\\nuser %Us\\nsys %Ss\\nmem %MKb', + // https://www.man7.org/linux/man-pages/man1/time.1.html#top_of_page + // elapsed user system memory + '%es %Us %Ss %MKb', ] if (memory_limit >= 0) { @@ -275,10 +277,16 @@ class Job { this.close_cleanup(); if (stderr.length > 0) { - var stats = stderr.trim().split('\n').slice(-4).join('\n'); + var stats = stderr.trim().split('\n').slice(-1).join('\n').split(' '); - stderr = stderr.trim().split('\n').slice(0, -4).join('\n'); - output = output.trim().split('\n').slice(0, -4).join('\n'); + stderr = stderr.trim().split('\n').slice(0, -1).join('\n'); + output = output.trim().split('\n').slice(0, -1).join('\n'); + + stats = { + 'elapsed_time': stats[0], + 'cpu_time': stats[1] + ' / ' + stats[2], + 'max_mem': stats[3], + } } var end_time = new Date().getTime(); @@ -293,10 +301,16 @@ class Job { this.close_cleanup(); if (stderr.length > 0) { - var stats = stderr.trim().split('\n').slice(-4).join('\n'); + var stats = stderr.trim().split('\n').slice(-1).join('\n').split(' '); - stderr = stderr.trim().split('\n').slice(0, -4).join('\n'); - output = output.trim().split('\n').slice(0, -4).join('\n'); + stderr = stderr.trim().split('\n').slice(0, -1).join('\n'); + output = output.trim().split('\n').slice(0, -1).join('\n'); + + stats = { + 'elapsed_time': stats[0], + 'cpu_time': stats[1] + ' / ' + stats[2], + 'max_mem': stats[3], + } } var end_time = new Date().getTime();