SchoolTool

Export does not work with Schooltool/Ubuntu installed on VirtualBox

Asked by Thomas Büsser

I have the problem, that the export does not work with Schooltool/Ubuntu installed on VirtualBox.
Everything else works perfectly fine.
When I start an export there is only the message:
---
"Scheduled.

You can close this dialogue and download the exported data later from your home page."
---

But no link is produced and in my message-center I got only these messages:
---
Message Group Received
Generating Thomas Büsser detail report...

2017-01-04 23:43
Generating school export...

2017-01-04 21:26
Generating school export...

---

Thanks for your help!

Question information

Language:
English Edit question
Status:
Expired
For:
SchoolTool Edit question
Assignee:
No assignee Edit question
Last query:
Last reply:
Revision history for this message
Thomas Büsser (thomasbuesser) said : 		#1

Here are some more informations:

I restartet the schooltool service several times.

I work with 14.04 LTS

The logs:
--
error.log:

2017-01-02 19:35:41,581 ['/var/run/schooltool/zeo.sock'] ClientStorage (pid=1241) created RW/normal for storage: '1'
2017-01-02 19:35:41,584 created temporary cache file '<fdopen>'
2017-01-02 19:35:41,589 ['/var/run/schooltool/zeo.sock'] Testing connection <ManagedClientConnection /var/run/schooltool/zeo.sock>
2017-01-02 19:35:41,591 (/var/run/schooltool/zeo.sock) received handshake 'Z3101'
2017-01-02 19:35:41,692 ['/var/run/schooltool/zeo.sock'] Server authentication protocol None
2017-01-02 19:35:41,693 ['/var/run/schooltool/zeo.sock'] Connected to storage: /var/run/schooltool/zeo.sock
2017-01-02 19:35:41,694 ['/var/run/schooltool/zeo.sock'] No verification necessary -- empty cache
2017-01-02 19:35:41,706 main db: evolving in mode EVOLVEMINIMUM
2017-01-02 21:30:11,664 ['/var/run/schooltool/zeo.sock'] ClientStorage (pid=2386) created RW/normal for storage: '1'
2017-01-02 21:30:11,666 created temporary cache file '<fdopen>'
2017-01-02 21:30:11,675 ['/var/run/schooltool/zeo.sock'] Testing connection <ManagedClientConnection /var/run/schooltool/zeo.sock>
2017-01-02 21:30:11,676 (/var/run/schooltool/zeo.sock) received handshake 'Z3101'
2017-01-02 21:30:11,779 ['/var/run/schooltool/zeo.sock'] Server authentication protocol None
2017-01-02 21:30:11,781 ['/var/run/schooltool/zeo.sock'] Connected to storage: /var/run/schooltool/zeo.sock
2017-01-02 21:30:11,783 ['/var/run/schooltool/zeo.sock'] No verification necessary -- empty cache
2017-01-02 21:30:11,801 main db: evolving in mode EVOLVEMINIMUM
2017-01-04 16:07:02,427 ['/var/run/schooltool/zeo.sock'] ClientStorage (pid=3737) created RW/normal for storage: '1'
2017-01-04 16:07:02,428 created temporary cache file '<fdopen>'
2017-01-04 16:07:02,446 ['/var/run/schooltool/zeo.sock'] Testing connection <ManagedClientConnection /var/run/schooltool/zeo.sock>
2017-01-04 16:07:02,447 (/var/run/schooltool/zeo.sock) received handshake 'Z3101'
2017-01-04 16:07:02,547 ['/var/run/schooltool/zeo.sock'] Server authentication protocol None
2017-01-04 16:07:02,549 ['/var/run/schooltool/zeo.sock'] Connected to storage: /var/run/schooltool/zeo.sock
2017-01-04 16:07:02,551 ['/var/run/schooltool/zeo.sock'] No verification necessary -- empty cache
2017-01-04 16:07:02,612 main db: evolving in mode EVOLVEMINIMUM
2017-01-04 16:29:19,927 ['/var/run/schooltool/zeo.sock'] ClientStorage (pid=1246) created RW/normal for storage: '1'
2017-01-04 16:29:19,932 created temporary cache file '<fdopen>'
2017-01-04 16:29:19,947 ['/var/run/schooltool/zeo.sock'] Testing connection <ManagedClientConnection /var/run/schooltool/zeo.sock>
2017-01-04 16:29:19,947 (/var/run/schooltool/zeo.sock) received handshake 'Z3101'
2017-01-04 16:29:20,051 ['/var/run/schooltool/zeo.sock'] Server authentication protocol None
2017-01-04 16:29:20,053 ['/var/run/schooltool/zeo.sock'] Connected to storage: /var/run/schooltool/zeo.sock
2017-01-04 16:29:20,056 ['/var/run/schooltool/zeo.sock'] No verification necessary -- empty cache
2017-01-04 16:29:20,117 main db: evolving in mode EVOLVEMINIMUM
2017-01-04 19:23:12,373 ['/var/run/schooltool/zeo.sock'] ClientStorage (pid=1237) created RW/normal for storage: '1'
2017-01-04 19:23:12,376 created temporary cache file '<fdopen>'
2017-01-04 19:23:12,383 ['/var/run/schooltool/zeo.sock'] Testing connection <ManagedClientConnection /var/run/schooltool/zeo.sock>
2017-01-04 19:23:12,384 (/var/run/schooltool/zeo.sock) received handshake 'Z3101'
2017-01-04 19:47:00,134 ['/var/run/schooltool/zeo.sock'] Server authentication protocol None
2017-01-04 19:47:00,135 ['/var/run/schooltool/zeo.sock'] Connected to storage: /var/run/schooltool/zeo.sock
2017-01-04 19:47:00,146 ['/var/run/schooltool/zeo.sock'] No verification necessary -- empty cache
2017-01-04 19:47:00,200 main db: evolving in mode EVOLVEMINIMUM
---

celery_report

[2017-01-02 21:29:46,245: WARNING/Worker-1] (1944) CW: error connecting to /var/run/schooltool/zeo.sock: ECONNREFUSED
("\nThe 'celeryd' command is deprecated, please use 'celery worker' instead:\n\n$ celery worker --loader=schooltool.task.celery:ReportLoader --config=schooltool.task.con$

 -------------- celery@thomas-VirtualBox v3.1.6 (Cipater)
---- **** -----
--- * *** * -- Linux-4.4.0-31-generic-i686-with-Ubuntu-14.04-trusty
-- * - **** ---
- ** ---------- [config]
- ** ---------- .> broker: redis://127.0.0.1:7079/0
- ** ---------- .> app: default:0xb6e0420c (schooltool.task.celery.ReportLoader)
- ** ---------- .> concurrency: 1 (prefork)
- *** --- * --- .> events: OFF (enable -E to monitor this worker)
-- ******* ----
--- ***** ----- [queues]
 -------------- .> default exchange=default(direct) key=default
                .> zodb.report exchange=zodb.report(direct) key=zodb.report

[2017-01-02 21:29:58,155: WARNING/MainProcess] celery@thomas-VirtualBox ready.

[2017-01-04 16:06:43,972: WARNING/MainProcess] celery@thomas-VirtualBox ready.

worker: Cold shutdown (MainProcess)
[2017-01-04 16:27:24,475: WARNING/Worker-1] (3753) CW: error connecting to /var/run/schooltool/zeo.sock: ECONNREFUSED

worker: Warm shutdown (MainProcess)
("\nThe 'celeryd' command is deprecated, please use 'celery worker' instead:\n\n$ celery worker --loader=schooltool.task.celery:ReportLoader --config=schooltool.task.con$

 -------------- celery@thomas-VirtualBox v3.1.6 (Cipater)
---- **** -----
--- * *** * -- Linux-4.4.0-31-generic-i686-with-Ubuntu-14.04-trusty
-- * - **** ---
- ** ---------- [config]
- ** ---------- .> broker: redis://127.0.0.1:7079/0
- ** ---------- .> app: default:0xb6c2430c (schooltool.task.celery.ReportLoader)
- ** ---------- .> concurrency: 1 (prefork)
- *** --- * --- .> events: OFF (enable -E to monitor this worker)
-- ******* ----
--- ***** ----- [queues]
 -------------- .> default exchange=default(direct) key=default
                .> zodb.report exchange=zodb.report(direct) key=zodb.report

[2017-01-04 16:28:50,583: WARNING/MainProcess] celery@thomas-VirtualBox ready.

worker: Cold shutdown (MainProcess)
[2017-01-04 19:20:54,231: WARNING/Worker-1] (2006) CW: error connecting to /var/run/schooltool/zeo.sock: ECONNREFUSED

worker: Warm shutdown (MainProcess)
("\nThe 'celeryd' command is deprecated, please use 'celery worker' instead:\n\n$ celery worker --loader=schooltool.task.celery:ReportLoader --config=schooltool.task.con$

 -------------- celery@thomas-VirtualBox v3.1.6 (Cipater)
---- **** -----
--- * *** * -- Linux-4.4.0-31-generic-i686-with-Ubuntu-14.04-trusty
-- * - **** ---

- ** ---------- [config]
- ** ---------- .> broker: redis://127.0.0.1:7079/0
- ** ---------- .> app: default:0xb6e1620c (schooltool.task.celery.ReportLoader)
- ** ---------- .> concurrency: 1 (prefork)
- *** --- * --- .> events: OFF (enable -E to monitor this worker)
-- ******* ----
--- ***** ----- [queues]
 -------------- .> default exchange=default(direct) key=default
                .> zodb.report exchange=zodb.report(direct) key=zodb.report

[2017-01-04 19:22:52,824: WARNING/MainProcess] celery@thomas-VirtualBox ready.

worker: Cold shutdown (MainProcess)
[2017-01-04 19:36:03,049: WARNING/Worker-1] (2014) CW: error connecting to /var/run/schooltool/zeo.sock: ECONNREFUSED
("\nThe 'celeryd' command is deprecated, please use 'celery worker' instead:\n\n$ celery worker --loader=schooltool.task.celery:ReportLoader --config=schooltool.task.con$

 -------------- celery@thomas-VirtualBox v3.1.6 (Cipater)
---- **** -----
--- * *** * -- Linux-4.4.0-31-generic-i686-with-Ubuntu-14.04-trusty
-- * - **** ---
- ** ---------- [config]
- ** ---------- .> broker: redis://127.0.0.1:7079/0
- ** ---------- .> app: default:0xb6e7a20c (schooltool.task.celery.ReportLoader)
- ** ---------- .> concurrency: 1 (prefork)
- *** --- * --- .> events: OFF (enable -E to monitor this worker)
-- ******* ----
--- ***** ----- [queues]
 -------------- .> default exchange=default(direct) key=default
                .> zodb.report exchange=zodb.report(direct) key=zodb.report

[2017-01-04 19:46:42,859: WARNING/MainProcess] celery@thomas-VirtualBox ready.

---
supervisord.log

2017-01-04 16:06:28,021 INFO waiting for redis, zeo, celery_report, schooltool to die
2017-01-04 16:06:28,073 WARN received SIGTERM indicating exit request
2017-01-04 16:06:28,850 INFO stopped: schooltool (terminated by SIGQUIT (core dumped))
2017-01-04 16:06:29,462 INFO stopped: zeo (terminated by SIGQUIT (core dumped))
2017-01-04 16:06:29,499 INFO stopped: redis (terminated by SIGQUIT (core dumped))
2017-01-04 16:06:31,143 INFO waiting for celery_report to die
2017-01-04 16:06:33,624 INFO stopped: celery_report (exit status 0)
2017-01-04 16:06:36,002 CRIT Set uid to user 117
2017-01-04 16:06:36,041 INFO RPC interface 'supervisor' initialized
2017-01-04 16:06:36,041 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2017-01-04 16:06:36,047 INFO daemonizing the supervisord process
2017-01-04 16:06:36,054 INFO supervisord started with pid 3729
2017-01-04 16:06:37,068 INFO spawned: 'redis' with pid 3732
2017-01-04 16:06:37,103 INFO spawned: 'zeo' with pid 3733
2017-01-04 16:06:37,170 INFO spawned: 'celery_report' with pid 3734
2017-01-04 16:06:37,209 INFO spawned: 'schooltool' with pid 3737
2017-01-04 16:06:38,241 INFO success: redis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2017-01-04 16:06:38,241 INFO success: zeo entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2017-01-04 16:06:38,241 INFO success: celery_report entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2017-01-04 16:06:43,058 INFO success: schooltool entered RUNNING state, process has stayed up for > than 5 seconds (startsecs)
2017-01-04 16:27:24,408 INFO waiting for redis, zeo, celery_report, schooltool to die
2017-01-04 16:27:24,438 WARN received SIGTERM indicating exit request
2017-01-04 16:27:24,441 INFO stopped: schooltool (terminated by SIGQUIT)
2017-01-04 16:27:24,463 INFO stopped: redis (terminated by SIGQUIT)
2017-01-04 16:27:24,474 INFO stopped: zeo (terminated by SIGQUIT)
2017-01-04 16:27:25,185 WARN received SIGTERM indicating exit request
2017-01-04 16:27:25,734 INFO stopped: celery_report (exit status 0)
2017-01-04 16:28:26,634 CRIT Set uid to user 117
2017-01-04 16:28:26,693 INFO RPC interface 'supervisor' initialized
2017-01-04 16:28:26,694 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2017-01-04 16:28:26,701 INFO daemonizing the supervisord process
2017-01-04 16:28:26,709 INFO supervisord started with pid 1181
2017-01-04 16:28:26,782 INFO spawned: 'redis' with pid 1241
2017-01-04 16:28:26,850 INFO spawned: 'zeo' with pid 1244
2017-01-04 16:28:26,901 INFO spawned: 'celery_report' with pid 1245
2017-01-04 16:28:27,004 INFO spawned: 'schooltool' with pid 1246
2017-01-04 16:28:28,074 INFO success: redis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2017-01-04 16:28:28,074 INFO success: zeo entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2017-01-04 16:28:28,074 INFO success: celery_report entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2017-01-04 16:28:32,142 INFO success: schooltool entered RUNNING state, process has stayed up for > than 5 seconds (startsecs)
2017-01-04 19:20:54,029 INFO waiting for redis, zeo, celery_report, schooltool to die
2017-01-04 19:20:54,073 INFO stopped: schooltool (terminated by SIGQUIT)
2017-01-04 19:20:54,074 WARN received SIGTERM indicating exit request
2017-01-04 19:20:54,113 INFO stopped: redis (terminated by SIGQUIT)
2017-01-04 19:20:54,113 INFO stopped: zeo (terminated by SIGQUIT)
2017-01-04 19:20:54,911 WARN received SIGTERM indicating exit request
2017-01-04 19:20:57,118 INFO stopped: celery_report (exit status 0)
2017-01-04 19:22:24,191 CRIT Set uid to user 117
2017-01-04 19:22:24,262 INFO RPC interface 'supervisor' initialized
2017-01-04 19:22:24,262 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2017-01-04 19:22:24,278 INFO daemonizing the supervisord process
2017-01-04 19:22:24,282 INFO supervisord started with pid 1180
2017-01-04 19:22:25,306 INFO spawned: 'redis' with pid 1221
2017-01-04 19:22:25,368 INFO spawned: 'zeo' with pid 1224

2017-01-04 19:22:25,469 INFO spawned: 'celery_report' with pid 1229
2017-01-04 19:22:25,603 INFO spawned: 'schooltool' with pid 1237
2017-01-04 19:22:26,663 INFO success: redis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2017-01-04 19:22:26,663 INFO success: zeo entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2017-01-04 19:22:26,663 INFO success: celery_report entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2017-01-04 19:22:30,723 INFO success: schooltool entered RUNNING state, process has stayed up for > than 5 seconds (startsecs)
2017-01-04 19:36:01,364 INFO waiting for redis, zeo, celery_report, schooltool to die
2017-01-04 19:36:01,405 WARN received SIGTERM indicating exit request
2017-01-04 19:36:02,107 INFO stopped: schooltool (terminated by SIGQUIT (core dumped))
2017-01-04 19:36:02,875 INFO stopped: redis (terminated by SIGQUIT (core dumped))
2017-01-04 19:36:03,049 INFO stopped: zeo (terminated by SIGQUIT (core dumped))
2017-01-04 19:36:04,405 INFO waiting for celery_report to die
2017-01-04 19:36:04,813 INFO stopped: celery_report (exit status 0)
2017-01-04 19:46:33,135 CRIT Set uid to user 117
2017-01-04 19:46:33,172 INFO RPC interface 'supervisor' initialized
2017-01-04 19:46:33,173 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2017-01-04 19:46:33,181 INFO daemonizing the supervisord process
2017-01-04 19:46:33,187 INFO supervisord started with pid 3490
2017-01-04 19:46:34,223 INFO spawned: 'redis' with pid 3493
2017-01-04 19:46:34,261 INFO spawned: 'zeo' with pid 3494
2017-01-04 19:46:34,316 INFO spawned: 'celery_report' with pid 3495
2017-01-04 19:46:34,344 INFO spawned: 'schooltool' with pid 3496
2017-01-04 19:46:35,372 INFO success: redis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2017-01-04 19:46:35,372 INFO success: zeo entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2017-01-04 19:46:35,372 INFO success: celery_report entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2017-01-04 19:46:39,391 INFO success: schooltool entered RUNNING state, process has stayed up for > than 5 seconds (startsecs)

--

zeo.log

2017-01-04T16:06:38 INFO ZEO.runzeo (3733) opening storage '1' using FileStorage
------
2017-01-04T16:06:38 INFO ZEO.StorageServer StorageServer created RW with storages: 1:RW:/var/lib/schooltool/Data.fs
------
2017-01-04T16:06:38 INFO ZEO.zrpc (3733) listening on /var/run/schooltool/zeo.sock
------
2017-01-04T16:07:02 INFO ZEO.StorageServer new connection : <ManagedServerConnection >
------
2017-01-04T16:07:02 INFO ZEO.StorageServer new connection : <ManagedServerConnection >
------
2017-01-04T16:07:02 INFO ZEO.zrpc.Connection(S) () received handshake 'Z3101'
------
2017-01-04T16:07:02 INFO ZEO.StorageServer new connection : <ManagedServerConnection >
------
2017-01-04T16:07:02 INFO ZEO.zrpc.Connection(S) () received handshake 'Z3101'
------
2017-01-04T16:27:24 INFO ZEO.StorageServer disconnected
------
2017-01-04T16:28:29 INFO ZEO.runzeo (1244) opening storage '1' using FileStorage
------
2017-01-04T16:28:30 INFO ZEO.StorageServer StorageServer created RW with storages: 1:RW:/var/lib/schooltool/Data.fs
------
2017-01-04T16:28:30 INFO ZEO.zrpc (1244) listening on /var/run/schooltool/zeo.sock
------
2017-01-04T16:29:19 INFO ZEO.zrpc.Connection(S) () received handshake 'Z3101'
------
2017-01-04T16:29:19 INFO ZEO.StorageServer new connection : <ManagedServerConnection >
------
2017-01-04T16:29:19 INFO ZEO.zrpc.Connection(S) () received handshake 'Z3101'
------
2017-01-04T19:20:54 INFO ZEO.StorageServer disconnected
------
2017-01-04T19:22:28 INFO ZEO.runzeo (1224) opening storage '1' using FileStorage
------
2017-01-04T19:22:29 INFO ZEO.StorageServer StorageServer created RW with storages: 1:RW:/var/lib/schooltool/Data.fs
------
2017-01-04T19:22:29 INFO ZEO.zrpc (1224) listening on /var/run/schooltool/zeo.sock
------
2017-01-04T19:23:11 INFO ZEO.StorageServer new connection : <ManagedServerConnection >
------
2017-01-04T19:23:12 INFO ZEO.zrpc.Connection(S) () received handshake 'Z3101'
------
2017-01-04T19:36:02 INFO ZEO.StorageServer disconnected
------
2017-01-04T19:46:35 INFO ZEO.runzeo (3494) opening storage '1' using FileStorage
------
2017-01-04T19:46:36 INFO ZEO.StorageServer StorageServer created RW with storages: 1:RW:/var/lib/schooltool/Data.fs
------
2017-01-04T19:46:36 INFO ZEO.zrpc (3494) listening on /var/run/schooltool/zeo.sock
------
2017-01-04T19:46:59 INFO ZEO.StorageServer new connection : <ManagedServerConnection >
------
2017-01-04T19:46:59 INFO ZEO.zrpc.Connection(S) () received handshake 'Z3101'
------
2017-01-04T19:47:00 INFO ZEO.StorageServer new connection : <ManagedServerConnection >
------
2017-01-04T19:47:00 INFO ZEO.zrpc.Connection(S) () received handshake 'Z3101'
------
2017-01-04T19:49:22 INFO ZEO.StorageServer pack(time=1483555762.695744) started...
------
2017-01-04T19:49:22 INFO ZEO.StorageServer pack(time=1483555762.695744) complete

Revision history for this message
Thomas Büsser (thomasbuesser) said : 		#2

And even more info:

I copied the Data.fs to an NON-VM-Ubuntu and SchoolTool-Installation --> Everything and especialy the export work perfectly.

I only had to ajust the permission-settings of Data.fs.

Is this a good way to export Schooltool-data?

Thanks a lot for all your advices.

Revision history for this message
Douglas Cerna (replaceafill) said : 		#3

Hi Thomas.

Regarding the VirtualBox problem, I have seen similar issues with the exports/reports not being produced when the VM or server doesn't have enough RAM. That's probably why it's now working on your NON-VM server. Just an idea ofc. And when you move the database from one server to another it's also a good idea to move the /var/lib/schooltool/blobs directory too (http://book.schooltool.org/database.html).

Revision history for this message
Thomas Büsser (thomasbuesser) said : 		#4

Dear Douglas

Thank you for your response. As I was searching for an answer to my problem, I found the hint about the RAM before. I switched to 2048 MB and now to 4096.
But it did not work - sadly.
Thanks too for the adwise about the blobs directory.

Revision history for this message
Launchpad Janitor (janitor) said : 		#5

This question was expired because it remained in the 'Open' state without activity for the last 15 days.

Revision history for this message
Thomas Büsser (thomasbuesser) said : 		#6

Sadly the problem is not solved yet.

--

Thomas Büsser
Schmidenhoschet 6
8753 Mollis

-----Ursprüngliche Nachricht-----
Von: <email address hidden> [mailto:<email address hidden>] Im Auftrag von Launchpad Janitor
Gesendet: 22 January 2017 10:49
An: <email address hidden>
Betreff: Re: [Question #429609]: Export does not work with Schooltool/Ubuntu installed on VirtualBox

Your question #429609 on SchoolTool changed:
https://answers.launchpad.net/schooltool/+question/429609

    Status: Open => Expired

Launchpad Janitor expired the question:
This question was expired because it remained in the 'Open' state without activity for the last 15 days.

--
If you're still having this problem, you can reopen your question either by replying to this email or by going to the following page and entering more information about your problem:
https://answers.launchpad.net/schooltool/+question/429609

You received this question notification because you asked the question.

Revision history for this message
Launchpad Janitor (janitor) said : 		#7

This question was expired because it remained in the 'Open' state without activity for the last 15 days.