Always get status 3 in the callback handler after restore a file version

Docs
1

We are researching the features of OnlyOffice and are considering using it, but we found that after restoring the file to a previous version, we are unable to save the document after editing it again.

Do you want to: Report a bug

For bug reports, provide the steps to reproduce and if possible a minimal demo of the problem.

  1. The Document Server I used: onlyoffice/documentserver:8.0.1
    the command i run the server is:
docker run -i -t -d -p 80:80 --restart=always -e JWT_ENABLED=false -e USE_UNAUTHORIZED_STORAGE=true -e ONLYOFFICE_HTTPS_HSTS_ENABLED=false onlyoffice/documentserver:8.0.1

  1. Run the Node.js Example at port 3000
    the example is downloaded from here: ONLYOFFICE Api Documentation - Language-specific examples

  2. Create a new ppt and edit it on the example page

    create a ppt file
    create a ppt file1254×664 30.4 KB

  3. Then restore the file

    restore the ppt
    restore the ppt1194×628 41.9 KB

  4. Refresh the page and edit the ppt file, then close the page, the node.js /track callback get the status: 3
    here is the request boy the callback get:
    {“key”:“__ffff_192.168.1.6new.pptx31713422847520”,“status”:3,“users”:[“uid-1”],“actions”:[{“type”:0,“userid”:“uid-1”}],“lastsave”:“2024-04-18T06:47:57.000Z”,“notmodified”:false}

Document Server version: 8.0.1
Type of installation of the Document Server: docker
OS: MacOS Ventura 13.5 with Apple M2
Browser version: Chrome 123.0.6312.59 (arm64)

2

Hello @zephan

In order to get more data about theissue I’d kindly ask you to enable DEBUG level logging on Document Server side, reproduce the issue and provide logs afterwards for analysis.
To enable DEBUG level logging please do the following:

  1. Connect to Document Server container with docker exec -it <ID> bash where <ID> is the ID of the container (use docker ps to enlist all running containers);
  2. Go to etc/onlyoffice/documentserver/log4js/ directory and open production.json config;
  3. Change value of "level" parameter to DEBUG like that:
  "categories": {
    "default": {
      "appenders": [
        "default"
      ],
      "level": "DEBUG"
  1. Restart Document Server services with command supervisorctl restart all to apply this change.

After that please reproduce the issue in your NodeJS test example and provide logs.

In addition, I’d be handy to know if this scenario is reproducible in integrated test example built into Document Server and available from its Welcome Page.

3

Hello @Constantine

I have reproduced this issue in the integrated test example built into Document Server. Attached are the relevant log records. Please let me know if you need more information. Thank you.

2024-04-22 13:18:39 [2024-04-22T05:18:39.271] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - data.type = versionHistory
2024-04-22 13:18:39 [2024-04-22T05:18:39.279] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - Start command: {"c":"open","id":"192.168.65.1new.pptx11713752238937","userid":"uid-1","format":"pptx","url":"http://192.168.25.147/example/history?fileName=new.pptx&file=prev.pptx&ver=2&useraddress=192.168.65.1","title":"new.pptx","userconnectionid":"uid-11","lcid":9,"closeonerror":true,"serverVersion":"8.0.1","nobase64":true,"convertToOrigin":".pdf.xps.oxps.djvu"}
2024-04-22 13:18:39 [2024-04-22T05:18:39.280] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - getBaseUrlByConnection host=192.168.25.147 x-forwarded-host=192.168.25.147 x-forwarded-proto=http x-forwarded-prefix=undefined cloudfront-forwarded-proto=undefined 
2024-04-22 13:18:39 [2024-04-22T05:18:39.367] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - Response command: {"type":"open","status":"updateversion","data":{"Editor.bin":"http://192.168.25.147/cache/files/data/192.168.65.1new.pptx11713752238937/Editor.bin/Editor.bin?md5=aj2ZRj95tl6G_zaOf28PAQ&expires=1716357486&WOPISrc=192.168.65.1new.pptx31713762978857&filename=Editor.bin"},"openedAt":1713791693859}
2024-04-22 13:18:39 [2024-04-22T05:18:39.368] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - sendData: type = documentOpen
2024-04-22 13:18:39 [2024-04-22T05:18:39.368] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - End command
2024-04-22 13:18:39 [2024-04-22T05:18:39.374] [INFO] [localhost] [192.168.65.1new.pptx11713752238937] [userId] nodeJS - Start downloadFile
2024-04-22 13:18:39 [2024-04-22T05:18:39.407] [INFO] [localhost] [192.168.65.1new.pptx11713752238937] [userId] nodeJS - End downloadFile
2024-04-22 13:18:39 [2024-04-22T05:18:39.410] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - data.type = clientLog
2024-04-22 13:18:39 [2024-04-22T05:18:39.410] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - clientLog: onDownloadFile time:41
2024-04-22 13:18:39 [2024-04-22T05:18:39.434] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - data.type = clientLog
2024-04-22 13:18:39 [2024-04-22T05:18:39.434] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - data.type = clientLog
2024-04-22 13:18:39 [2024-04-22T05:18:39.434] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - clientLog: onLoadFonts time:1
2024-04-22 13:18:39 [2024-04-22T05:18:39.434] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - clientLog: onOpenDocument time:23
2024-04-22 13:18:39 [2024-04-22T05:18:39.471] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - data.type = clientLog
2024-04-22 13:18:39 [2024-04-22T05:18:39.471] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - clientLog: onApplyChanges time:35
2024-04-22 13:18:39 [2024-04-22T05:18:39.484] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - data.type = clientLog
2024-04-22 13:18:39 [2024-04-22T05:18:39.484] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - clientLog: onDocumentContentReady memory:{"totalJSHeapSize":95405420,"usedJSHeapSize":87308204,"jsHeapSizeLimit":4294705152}
2024-04-22 13:19:08 [2024-04-22T05:19:08.952] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - data.type = close
2024-04-22 13:19:08 [2024-04-22T05:19:08.954] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - Connection closed or timed out: reason = undefined
2024-04-22 13:19:08 [2024-04-22T05:19:08.988] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - data.type = versionHistory
2024-04-22 13:19:08 [2024-04-22T05:19:08.993] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - Start command: {"c":"open","id":"192.168.65.1new.pptx41713763148931","userid":"uid-1","format":"pptx","url":"http://192.168.25.147/example/download?fileName=new.pptx&useraddress=192.168.65.1","title":"new.pptx","userconnectionid":"uid-11","lcid":9,"closeonerror":true,"serverVersion":0,"nobase64":true,"convertToOrigin":".pdf.xps.oxps.djvu"}
2024-04-22 13:19:08 [2024-04-22T05:19:08.993] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - getBaseUrlByConnection host=192.168.25.147 x-forwarded-host=192.168.25.147 x-forwarded-proto=http x-forwarded-prefix=undefined cloudfront-forwarded-proto=undefined 
2024-04-22 13:19:09 [2024-04-22T05:19:09.010] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - End command
2024-04-22 13:19:09 
2024-04-22 13:19:09 ==> /var/log/onlyoffice/documentserver/converter/out.log <==
2024-04-22 13:19:09 [2024-04-22T05:19:09.018] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - Start Task
2024-04-22 13:19:09 [2024-04-22T05:19:09.034] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - downloadFile complete filesize=32590 sha256=d4e95d6d854bf3fbcba3a8d1e6b3107006349972740f48bfdd74bcdd9044c9aa
2024-04-22 13:19:09 [2024-04-22T05:19:09.129] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - stdout:
2024-04-22 13:19:09 [2024-04-22T05:19:09.129] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - stderr:
2024-04-22 13:19:09 [2024-04-22T05:19:09.129] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - ExitCode (code=0;signal=null;error:0)
2024-04-22 13:19:09 [2024-04-22T05:19:09.131] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - processUploadToStorage complete
2024-04-22 13:19:09 [2024-04-22T05:19:09.132] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - output (data={"ctx":{"tenant":"localhost","docId":"192.168.65.1new.pptx31713762978857","userId":"uid-11","shardKey":"192.168.65.1new.pptx31713762978857"},"cmd":{"c":"open","id":"192.168.65.1new.pptx41713763148931","userid":"uid-1","format":"pptx","url":"http://192.168.25.147/example/download?fileName=new.pptx&useraddress=192.168.65.1","title":"new.pptx","outputformat":8195,"outputpath":"Editor.bin","embeddedfonts":false,"status_info":0,"userconnectionid":"uid-11","lcid":9,"closeonerror":true,"serverVersion":0,"nobase64":true,"convertToOrigin":".pdf.xps.oxps.djvu"}})
2024-04-22 13:19:09 [2024-04-22T05:19:09.132] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - postProcess
2024-04-22 13:19:09 [2024-04-22T05:19:09.133] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - deleteFolderRecursive
2024-04-22 13:19:09 [2024-04-22T05:19:09.133] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - End Task
2024-04-22 13:19:09 
2024-04-22 13:19:09 ==> /var/log/onlyoffice/documentserver/docservice/out.log <==
2024-04-22 13:19:09 [2024-04-22T05:19:09.135] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - receiveTask start: {"ctx":{"tenant":"localhost","docId":"192.168.65.1new.pptx31713762978857","userId":"uid-11","shardKey":"192.168.65.1new.pptx31713762978857"},"cmd":{"c":"open","id":"192.168.65.1new.pptx41713763148931","userid":"uid-1","format":"pptx","url":"http://192.168.25.147/example/download?fileName=new.pptx&useraddress=192.168.65.1","title":"new.pptx","outputformat":8195,"outputpath":"Editor.bin","embeddedfonts":false,"status_info":0,"userconnectionid":"uid-11","lcid":9,"closeonerror":true,"serverVersion":0,"nobase64":true,"convertToOrigin":".pdf.xps.oxps.djvu"}}
2024-04-22 13:19:09 
2024-04-22 13:19:09 ==> /var/log/onlyoffice/documentserver/converter/out.log <==
2024-04-22 13:19:09 [2024-04-22T05:19:09.135] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - ackTask addResponse
2024-04-22 13:19:09 [2024-04-22T05:19:09.135] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - ackTask ack
2024-04-22 13:19:09 
2024-04-22 13:19:09 ==> /var/log/onlyoffice/documentserver/docservice/out.log <==
2024-04-22 13:19:09 [2024-04-22T05:19:09.136] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - receiveTask publish: {"type":"open","status":"ok"}
2024-04-22 13:19:09 [2024-04-22T05:19:09.137] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - receiveTask end
2024-04-22 13:19:09 [2024-04-22T05:19:09.138] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - pubsub message start:{"type":7,"ctx":{"tenant":"localhost","docId":"192.168.65.1new.pptx31713762978857","userId":"uid-11","shardKey":"192.168.65.1new.pptx31713762978857"},"cmd":{"c":"open","id":"192.168.65.1new.pptx41713763148931","userid":"uid-1","format":"pptx","url":"http://192.168.25.147/example/download?fileName=new.pptx&useraddress=192.168.65.1","title":"new.pptx","outputformat":8195,"outputpath":"Editor.bin","embeddedfonts":false,"status_info":0,"userconnectionid":"uid-11","lcid":9,"closeonerror":true,"serverVersion":0,"nobase64":true,"convertToOrigin":".pdf.xps.oxps.djvu"},"output":{"type":"documentOpen","data":{"type":"open","status":"ok"}},"needUrlKey":"192.168.65.1new.pptx41713763148931","needUrlMethod":0,"needUrlType":0,"creationDate":1713763148996}
2024-04-22 13:19:09 [2024-04-22T05:19:09.139] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - sendData: type = documentOpen
2024-04-22 13:19:09 [2024-04-22T05:19:09.142] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - data.type = clientLog
2024-04-22 13:19:09 [2024-04-22T05:19:09.142] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - clientLog: onDownloadFile time:2
2024-04-22 13:19:09 [2024-04-22T05:19:09.173] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - data.type = clientLog
2024-04-22 13:19:09 [2024-04-22T05:19:09.174] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - data.type = clientLog
2024-04-22 13:19:09 [2024-04-22T05:19:09.174] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - clientLog: onLoadFonts time:1
2024-04-22 13:19:09 [2024-04-22T05:19:09.174] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - clientLog: onOpenDocument time:31
2024-04-22 13:19:09 [2024-04-22T05:19:09.218] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - data.type = clientLog
2024-04-22 13:19:09 [2024-04-22T05:19:09.218] [DEBUG] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - clientLog: onDocumentContentReady memory:{"totalJSHeapSize":98046318,"usedJSHeapSize":90010690,"jsHeapSizeLimit":4294705152}
2024-04-22 13:19:14 [2024-04-22T05:19:14.796] [INFO] [localhost] [docId] [userId] nodeJS - forceSaveTimeout start
2024-04-22 13:19:14 [2024-04-22T05:19:14.798] [INFO] [localhost] [docId] [userId] nodeJS - forceSaveTimeout end
2024-04-22 13:20:10 [2024-04-22T05:20:10.382] [INFO] [localhost] [192.168.65.1new.pptx31713762978857] [uid-11] nodeJS - Connection closed or timed out: reason = transport close
2024-04-22 13:20:10 [2024-04-22T05:20:10.565] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [userId] nodeJS - io.use start
2024-04-22 13:20:10 [2024-04-22T05:20:10.565] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [userId] nodeJS - io.use end
2024-04-22 13:20:10 [2024-04-22T05:20:10.566] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [userId] nodeJS - getBaseUrlByConnection host=192.168.25.147 x-forwarded-host=192.168.25.147 x-forwarded-proto=http x-forwarded-prefix=undefined cloudfront-forwarded-proto=undefined 
2024-04-22 13:20:10 [2024-04-22T05:20:10.572] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [userId] nodeJS - _checkLicense start
2024-04-22 13:20:10 [2024-04-22T05:20:10.573] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [userId] nodeJS - sendData: type = license
2024-04-22 13:20:10 [2024-04-22T05:20:10.573] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [userId] nodeJS - _checkLicense end
2024-04-22 13:20:10 [2024-04-22T05:20:10.620] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [userId] nodeJS - data.type = auth
2024-04-22 13:20:10 [2024-04-22T05:20:10.620] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [userId] nodeJS - auth time: 233
2024-04-22 13:20:10 [2024-04-22T05:20:10.623] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-1] nodeJS - getBaseUrlByConnection host=192.168.25.147 x-forwarded-host=192.168.25.147 x-forwarded-proto=http x-forwarded-prefix=undefined cloudfront-forwarded-proto=undefined 
2024-04-22 13:20:10 [2024-04-22T05:20:10.677] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-1] nodeJS - getCallbackByUserIndex: userIndex = 2 callbacks = {"userIndex":2,"callback":"http://192.168.25.147/example/track?filename=new.pptx&useraddress=192.168.65.1"}
2024-04-22 13:20:10 [2024-04-22T05:20:10.678] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-1] nodeJS - postData request: url = http://192.168.25.147/example/track?filename=new.pptx&useraddress=192.168.65.1;data = {"key":"192.168.65.1new.pptx41713763148931","status":1,"users":["uid-1"],"actions":[{"type":1,"userid":"uid-1"}]}
2024-04-22 13:20:10 [2024-04-22T05:20:10.683] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-1] nodeJS - endAuth hasForgotten false
2024-04-22 13:20:10 [2024-04-22T05:20:10.689] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-1] nodeJS - postData response: data = {"error":0}
2024-04-22 13:20:10 [2024-04-22T05:20:10.693] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-1] nodeJS - sendData: type = auth
2024-04-22 13:20:10 [2024-04-22T05:20:10.693] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-1] nodeJS - Start command: {"wopiParams":null,"c":"open","id":"192.168.65.1new.pptx41713763148931","userid":"uid-1","format":"pptx","url":"http://192.168.25.147/example/download?fileName=new.pptx&useraddress=192.168.65.1","title":"new.pptx","lcid":9,"nobase64":true,"convertToOrigin":".pdf.xps.oxps.djvu"}
2024-04-22 13:20:10 [2024-04-22T05:20:10.696] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-1] nodeJS - Response command: {"type":"open","status":"ok","data":{"Editor.bin":"http://192.168.25.147/cache/files/data/192.168.65.1new.pptx41713763148931/Editor.bin/Editor.bin?md5=rIJKkfICtxB-7RTREThGZg&expires=1716357741&WOPISrc=192.168.65.1new.pptx41713763148931&filename=Editor.bin"}}
2024-04-22 13:20:10 [2024-04-22T05:20:10.696] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-1] nodeJS - sendData: type = documentOpen
2024-04-22 13:20:10 [2024-04-22T05:20:10.696] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-1] nodeJS - End command
2024-04-22 13:20:10 [2024-04-22T05:20:10.700] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - data.type = clientLog
2024-04-22 13:20:10 [2024-04-22T05:20:10.700] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - clientLog: onDownloadFile time:3
2024-04-22 13:20:10 [2024-04-22T05:20:10.732] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - data.type = clientLog
2024-04-22 13:20:10 [2024-04-22T05:20:10.732] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - clientLog: onOpenDocument time:31
2024-04-22 13:20:10 [2024-04-22T05:20:10.781] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - data.type = clientLog
2024-04-22 13:20:10 [2024-04-22T05:20:10.781] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - clientLog: onLoadFonts time:51
2024-04-22 13:20:10 [2024-04-22T05:20:10.875] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - data.type = getMessages
2024-04-22 13:20:10 [2024-04-22T05:20:10.875] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - sendData: type = message
2024-04-22 13:20:10 [2024-04-22T05:20:10.902] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - data.type = clientLog
2024-04-22 13:20:10 [2024-04-22T05:20:10.902] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - clientLog: onDocumentContentReady time:491 memory:{"totalJSHeapSize":157018257,"usedJSHeapSize":139413917,"jsHeapSizeLimit":4294705152}
2024-04-22 13:20:10 [2024-04-22T05:20:10.966] [INFO] [localhost] [docId] [userId] nodeJS - themes.json start
2024-04-22 13:20:10 [2024-04-22T05:20:10.968] [DEBUG] [localhost] [docId] [userId] nodeJS - themes.json dir:/var/www/onlyoffice/documentserver/web-apps/apps/common/main/resources/themes
2024-04-22 13:20:10 [2024-04-22T05:20:10.968] [DEBUG] [localhost] [docId] [userId] nodeJS - themes.json themesList:["/var/www/onlyoffice/documentserver/web-apps/apps/common/main/resources/themes/themes.json","/var/www/onlyoffice/documentserver/web-apps/apps/common/main/resources/themes/themes.json.gz"]
2024-04-22 13:20:10 [2024-04-22T05:20:10.970] [INFO] [localhost] [docId] [userId] nodeJS - themes.json end
2024-04-22 13:20:14 [2024-04-22T05:20:14.697] [DEBUG] [localhost] [docId] [userId] nodeJS - expireDoc connections.length = 1
2024-04-22 13:20:14 [2024-04-22T05:20:14.791] [INFO] [localhost] [docId] [userId] nodeJS - checkDocumentExpire start
2024-04-22 13:20:14 [2024-04-22T05:20:14.792] [INFO] [localhost] [docId] [userId] nodeJS - checkDocumentExpire end: startSaveCount = 0, removedCount = 0
2024-04-22 13:20:14 [2024-04-22T05:20:14.800] [INFO] [localhost] [docId] [userId] nodeJS - forceSaveTimeout start
2024-04-22 13:20:14 [2024-04-22T05:20:14.800] [INFO] [localhost] [docId] [userId] nodeJS - forceSaveTimeout end
2024-04-22 13:20:15 [2024-04-22T05:20:15.055] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - data.type = isSaveLock
2024-04-22 13:20:15 [2024-04-22T05:20:15.055] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - isSaveLock lockRes: true
2024-04-22 13:20:15 [2024-04-22T05:20:15.056] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - sendData: type = saveLock
2024-04-22 13:20:15 [2024-04-22T05:20:15.064] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - data.type = saveChanges
2024-04-22 13:20:15 [2024-04-22T05:20:15.065] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - Start saveChanges: reSave: undefined
2024-04-22 13:20:15 [2024-04-22T05:20:15.069] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - saveChanges: deleteIndex: -1 ; startIndex: 0 ; length: 2
2024-04-22 13:20:15 [2024-04-22T05:20:15.077] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - sendData: type = unSaveLock
2024-04-22 13:20:15 [2024-04-22T05:20:15.078] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - getBaseUrlByConnection host=192.168.25.147 x-forwarded-host=192.168.25.147 x-forwarded-proto=http x-forwarded-prefix=undefined cloudfront-forwarded-proto=undefined 
2024-04-22 13:20:17 [2024-04-22T05:20:17.261] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - data.type = isSaveLock
2024-04-22 13:20:17 [2024-04-22T05:20:17.264] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - isSaveLock lockRes: true
2024-04-22 13:20:17 [2024-04-22T05:20:17.266] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - sendData: type = saveLock
2024-04-22 13:20:17 [2024-04-22T05:20:17.271] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - data.type = saveChanges
2024-04-22 13:20:17 [2024-04-22T05:20:17.272] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - Start saveChanges: reSave: undefined
2024-04-22 13:20:17 [2024-04-22T05:20:17.276] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - saveChanges: deleteIndex: 2 ; startIndex: 2 ; length: 2
2024-04-22 13:20:17 [2024-04-22T05:20:17.280] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - sendData: type = unSaveLock
2024-04-22 13:20:17 [2024-04-22T05:20:17.281] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - getBaseUrlByConnection host=192.168.25.147 x-forwarded-host=192.168.25.147 x-forwarded-proto=http x-forwarded-prefix=undefined cloudfront-forwarded-proto=undefined 
2024-04-22 13:20:19 [2024-04-22T05:20:19.293] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - data.type = isSaveLock
2024-04-22 13:20:19 [2024-04-22T05:20:19.293] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - isSaveLock lockRes: true
2024-04-22 13:20:19 [2024-04-22T05:20:19.294] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - sendData: type = saveLock
2024-04-22 13:20:19 [2024-04-22T05:20:19.300] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - data.type = saveChanges
2024-04-22 13:20:19 [2024-04-22T05:20:19.300] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - Start saveChanges: reSave: undefined
2024-04-22 13:20:19 [2024-04-22T05:20:19.304] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - saveChanges: deleteIndex: 4 ; startIndex: 4 ; length: 4
2024-04-22 13:20:19 [2024-04-22T05:20:19.309] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - sendData: type = unSaveLock
2024-04-22 13:20:19 [2024-04-22T05:20:19.310] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - getBaseUrlByConnection host=192.168.25.147 x-forwarded-host=192.168.25.147 x-forwarded-proto=http x-forwarded-prefix=undefined cloudfront-forwarded-proto=undefined 
2024-04-22 13:20:20 [2024-04-22T05:20:20.895] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - Connection closed or timed out: reason = transport close
2024-04-22 13:20:25 [2024-04-22T05:20:25.907] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - Start saveFromChanges
2024-04-22 13:20:25 [2024-04-22T05:20:25.914] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - getCallbackByUserIndex: userIndex = undefined callbacks = {"userIndex":2,"callback":"http://192.168.25.147/example/track?filename=new.pptx&useraddress=192.168.65.1"}
2024-04-22 13:20:25 [2024-04-22T05:20:25.934] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - AddTask saveFromChanges
2024-04-22 13:20:25 
2024-04-22 13:20:25 ==> /var/log/onlyoffice/documentserver/converter/out.log <==
2024-04-22 13:20:25 [2024-04-22T05:20:25.937] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - Start Task
2024-04-22 13:20:25 [2024-04-22T05:20:25.990] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - downloadFileFromStorage list 192.168.65.1new.pptx41713763148931/Editor.bin
2024-04-22 13:20:25 [2024-04-22T05:20:25.991] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - downloadFileFromStorage complete
2024-04-22 13:20:25 [2024-04-22T05:20:25.991] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - downloadFileFromStorage list 
2024-04-22 13:20:26 [2024-04-22T05:20:26.003] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - processChanges end
2024-04-22 13:20:26 [2024-04-22T05:20:26.061] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - error spawnAsync Error: Process exited with non-zero code: 88
2024-04-22 13:20:26     at ChildProcess.<anonymous> (/snapshot/server/FileConverter/node_modules/@expo/spawn-async/build/spawnAsync.js:39:21)
2024-04-22 13:20:26     at ChildProcess.emit (node:events:527:28)
2024-04-22 13:20:26     at maybeClose (node:internal/child_process:1092:16)
2024-04-22 13:20:26     at Process.ChildProcess._handle.onexit (node:internal/child_process:302:5)
2024-04-22 13:20:26 [2024-04-22T05:20:26.062] [ERROR] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - stdout:
2024-04-22 13:20:26 [2024-04-22T05:20:26.062] [ERROR] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - stderr:
2024-04-22 13:20:26 [2024-04-22T05:20:26.062] [ERROR] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - ExitCode (code=88;signal=null;error:-88)
2024-04-22 13:20:26 [2024-04-22T05:20:26.063] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - output (data={"ctx":{"tenant":"localhost","docId":"192.168.65.1new.pptx41713763148931","userId":"uid-12","shardKey":"192.168.65.1new.pptx41713763148931"},"cmd":{"wopiParams":null,"c":"sfc","id":"192.168.65.1new.pptx41713763148931","userid":"uid-1","userindex":2,"data":null,"title":"output.ooxml","outputformat":2055,"outputpath":"output.ooxml","status_info":-88,"savekey":"192.168.65.1new.pptx41713763148931_7014","useractionid":"uid-1","useractionindex":2,"nobase64":true,"status_info_in":1220897,"originformat":0}})
2024-04-22 13:20:26 [2024-04-22T05:20:26.063] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - postProcess
2024-04-22 13:20:26 [2024-04-22T05:20:26.064] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - deleteFolderRecursive
2024-04-22 13:20:26 [2024-04-22T05:20:26.064] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - End Task
2024-04-22 13:20:26 
2024-04-22 13:20:26 ==> /var/log/onlyoffice/documentserver/docservice/out.log <==
2024-04-22 13:20:26 [2024-04-22T05:20:26.065] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - receiveTask start: {"ctx":{"tenant":"localhost","docId":"192.168.65.1new.pptx41713763148931","userId":"uid-12","shardKey":"192.168.65.1new.pptx41713763148931"},"cmd":{"wopiParams":null,"c":"sfc","id":"192.168.65.1new.pptx41713763148931","userid":"uid-1","userindex":2,"data":null,"title":"output.ooxml","outputformat":2055,"outputpath":"output.ooxml","status_info":-88,"savekey":"192.168.65.1new.pptx41713763148931_7014","useractionid":"uid-1","useractionindex":2,"nobase64":true,"status_info_in":1220897,"originformat":0}}
2024-04-22 13:20:26 [2024-04-22T05:20:26.067] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - Start commandSfcCallback
2024-04-22 13:20:26 
2024-04-22 13:20:26 ==> /var/log/onlyoffice/documentserver/converter/out.log <==
2024-04-22 13:20:26 [2024-04-22T05:20:26.067] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - ackTask addResponse
2024-04-22 13:20:26 [2024-04-22T05:20:26.067] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - ackTask ack
2024-04-22 13:20:26 
2024-04-22 13:20:26 ==> /var/log/onlyoffice/documentserver/docservice/out.log <==
2024-04-22 13:20:26 [2024-04-22T05:20:26.068] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - getCallbackByUserIndex: userIndex = 2 callbacks = {"userIndex":2,"callback":"http://192.168.25.147/example/track?filename=new.pptx&useraddress=192.168.65.1"}
2024-04-22 13:20:26 [2024-04-22T05:20:26.068] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - Callback commandSfcCallback: callback = http://192.168.25.147/example/track?filename=new.pptx&useraddress=192.168.65.1
2024-04-22 13:20:26 [2024-04-22T05:20:26.068] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - commandSfcCallback presence: count = 0
2024-04-22 13:20:26 [2024-04-22T05:20:26.069] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - postData request: url = http://192.168.25.147/example/track?filename=new.pptx&useraddress=192.168.65.1;data = {"key":"192.168.65.1new.pptx41713763148931","status":3,"users":["uid-1"],"actions":[{"type":0,"userid":"uid-1"}],"lastsave":"2024-04-22T05:20:19.000Z","notmodified":false}
2024-04-22 13:20:26 [2024-04-22T05:20:26.081] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - postData response: data = {"error":1}
2024-04-22 13:20:26 [2024-04-22T05:20:26.081] [WARN] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - sendServerRequest returned an error: data = {"error":1}
2024-04-22 13:20:26 [2024-04-22T05:20:26.081] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - commandSfcCallback restore 7 status
2024-04-22 13:20:26 [2024-04-22T05:20:26.082] [DEBUG] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - End commandSfcCallback
2024-04-22 13:20:26 [2024-04-22T05:20:26.082] [INFO] [localhost] [192.168.65.1new.pptx41713763148931] [uid-12] nodeJS - receiveTask end
2024-04-22 13:21:14 [2024-04-22T05:21:14.804] [INFO] [localhost] [docId] [userId] nodeJS - forceSaveTimeout start
2024-04-22 13:21:14 [2024-04-22T05:21:14.808] [INFO] [localhost] [docId] [userId] nodeJS - forceSaveTimeout end
2024-04-22 13:22:14 [2024-04-22T05:22:14.705] [DEBUG] [localhost] [docId] [userId] nodeJS - expireDoc connections.length = 0
2024-04-22 13:22:14 [2024-04-22T05:22:14.794] [INFO] [localhost] [docId] [userId] nodeJS - checkDocumentExpire start
2024-04-22 13:22:14 [2024-04-22T05:22:14.794] [INFO] [localhost] [docId] [userId] nodeJS - checkDocumentExpire end: startSaveCount = 0, removedCount = 0
2024-04-22 13:22:14 [2024-04-22T05:22:14.809] [INFO] [localhost] [docId] [userId] nodeJS - forceSaveTimeout start
2024-04-22 13:22:14 [2024-04-22T05:22:14.810] [INFO] [localhost] [docId] [userId] nodeJS - forceSaveTimeout end
2024-04-22 13:23:14 [2024-04-22T05:23:14.817] [INFO] [localhost] [docId] [userId] nodeJS - forceSaveTimeout start
2024-04-22 13:23:14 [2024-04-22T05:23:14.820] [INFO] [localhost] [docId] [userId] nodeJS - forceSaveTimeout end

Due to attachment format restrictions, I placed the log records into the docx document.

logs.docx (14.7 KB)

4

Thank you for valuable data. I was able to reproduce the issue, we are analyzing it. I will let you know once we get any results.

6

Hello again @zephan

Recently we’ve released new version of Document Server. Please update your instance and check the issue in integrated test example again as I wasn’t able to reproduce it there.