Rsync task page error "No Closing Quotation"

[snowlucas]

Hi,

I have been trying to setup an rsync task using the built in editor. It was working as expected but I was trying to add a bit more detail to the logging from rsync by adding human readable figures into the log. When trying to save the changes under "extra options" I got a popup saying "No closing Quotation" and the error as below. The issue is now if I go to the rsync tab of the tasks dropdown the rsync tasks dont appear, the system appears to be trying to load them and the error "No closing quotation" appears again and again. Ideally I'd just remove the offending task but I am unable to do this through the web GUI as they do not load.

The extra option I tried to use was "--out-format="%t %f %'''b""

Am I able to remove the rsync task through shell? Could someone please point me in the right direction?

Any other ideas would be greatly appriecated. Thanks for your time.

More info displays the following:

Error: Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 130, in call_method
io_thread=False)
File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1084, in _call
return await methodobj(*args)
File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 961, in nf
return await f(*args, **kwargs)
File "/usr/local/lib/python3.7/site-packages/middlewared/service.py", line 383, in query
'datastore.query', self._config.datastore, [], datastore_options
File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1141, in call
app=app, pipes=pipes, job_on_progress_cb=job_on_progress_cb, io_thread=True,
File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
return await run_method(methodobj, *args)
File "/usr/local/lib/python3.7/site-packages/middlewared/utils/run_in_thread.py", line 10, in run_in_thread
return await self.loop.run_in_executor(self.run_in_thread_executor, functools.partial(method, *args, **kwargs))
File "/usr/local/lib/python3.7/site-packages/middlewared/utils/io_thread_pool_executor.py", line 25, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
return f(*args, **kwargs)
File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/datastore.py", line 192, in query
qs, options.get('extend'), options.get('extend_context'), options.get('prefix'), options.get('select'),
File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/datastore.py", line 98, in __queryset_serialize
select=select)
File "/usr/local/lib/python3.7/site-packages/middlewared/utils/__init__.py", line 77, in django_modelobj_serialize
data = middleware.call_sync(extend, data, extend_context_value)
File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1157, in call_sync
io_thread=True, job_on_progress_cb=job_on_progress_cb,
File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1180, in run_coroutine
return fut.result()
File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 428, in result
return self.__get_result()
File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 384, in __get_result
raise self._exception
File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1084, in _call
return await methodobj(*args)
File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/rsync.py", line 202, in rsync_task_extend
data['extra'] = shlex.split(data['extra'].replace('"', r'"\"').replace("'", r'"\"'))
File "/usr/local/lib/python3.7/shlex.py", line 309, in split
return list(lex)
File "/usr/local/lib/python3.7/shlex.py", line 299, in __next__
token = self.get_token()
File "/usr/local/lib/python3.7/shlex.py", line 109, in get_token
raw = self.read_token()
File "/usr/local/lib/python3.7/shlex.py", line 191, in read_token
raise ValueError("No closing quotation")
ValueError: No closing quotation

 

[Samuel Tai]

Am I able to remove the rsync task through shell? Could someone please point me in the right direction?

Yes, but it's not easy, and requires the root account to have password login enabled. You'll have to delete the offending rsync task via the FreeNAS REST 2.0 API.

1. First, try

Code:

curl --basic -u root -k -X GET "https://<your FreeNAS IP>/api/v2.0/rsynctask" -H "accept: */*"

to get a list of all the rsync tasks. Enter root's password when prompted.

2. From the list, get the ID number of the offending task. To delete the task, try

Code:

curl --basic -u root -k -X DELETE "https://<your FreeNAS IP>/api/v2.0/rsynctask/id/<task ID>" -H "accept: */*"

Note, you're operating directly on the FreeNAS database here, so make sure you get all the syntax and quotes right. The API does have some built-in safety nets, but it assumes you essentially know what you're doing.

 

[snowlucas]

Thanks for the help.

I tired to find the task ID but it just threw up the same old error so I just used the API to delete as you described and guessed the ID which has worked.

Again thanks!

 

[·HeRmAN·]

I have exactly the same problem.
Using 11.3-U3.2

Was configuring rsync and wanted to have log files created with date and time as partial file name so I used the 'Extra options' when creating the task for rsync and tested different syntax for --log-file=/mnt/POOL/logs/rsync/somename_'date +%Y-%m-%d_%H%M'.log
All tests gave a log file but not with the date and time as a part of the file name and somehow it went wrong and the error message show up and there is no way to correct the problem or to remove the task and start over.

Tested the tip by @Samuel Tai curl --basic -u root -k -X GET "https://<your FreeNAS IP>/api/v2.0/rsynctask" -H "accept: */*"
And it doesn't give and task list with ID's but this

Code:

{
"message": "No closing quotation",
"traceback": "Traceback (most recent call last):\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/restful.py\", line 543, in do\n    result = await self.middleware.call(methodname, *method_args, **method_kwargs)\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/main.py\", line 1141, in call\n    app=app, pipes=pipes, job_on_progress_cb=job_on_progress_cb, io_thread=True,\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/main.py\", line 1084, in _call\n    return await methodobj(*args)\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/schema.py\", line 961, in nf\n    return await f(*args, **kwargs)\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/service.py\", line 383, in query\n    'datastore.query', self._config.datastore, [], datastore_options\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/main.py\", line 1141, in call\n    app=app, pipes=pipes, job_on_progress_cb=job_on_progress_cb, io_thread=True,\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/main.py\", line 1098, in _call\n    return await run_method(methodobj, *args)\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/utils/run_in_thread.py\", line 10, in run_in_thread\n    return await self.loop.run_in_executor(self.run_in_thread_executor, functools.partial(method, *args, **kwargs))\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/utils/io_thread_pool_executor.py\", line 25, in run\n    result = self.fn(*self.args, **self.kwargs)\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/schema.py\", line 965, in nf\n    return f(*args, **kwargs)\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/plugins/datastore.py\", line 192, in query\n    qs, options.get('extend'), options.get('extend_context'), options.get('prefix'), options.get('select'),\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/plugins/datastore.py\", line 98, in __queryset_serialize\n    select=select)\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/utils/__init__.py\", line 77, in django_modelobj_serialize\n    data = middleware.call_sync(extend, data, extend_context_value)\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/main.py\", line 1157, in call_sync\n    io_thread=True, job_on_progress_cb=job_on_progress_cb,\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/main.py\", line 1180, in run_coroutine\n    return fut.result()\n  File \"/usr/local/lib/python3.7/concurrent/futures/_base.py\", line 428, in result\n    return self.__get_result()\n  File \"/usr/local/lib/python3.7/concurrent/futures/_base.py\", line 384, in __get_result\n    raise self._exception\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/main.py\", line 1084, in _call\n    return await methodobj(*args)\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/plugins/rsync.py\", line 202, in rsync_task_extend\n    data['extra'] = shlex.split(data['extra'].replace('\"', r'\"\\\"').replace(\"'\", r'\"\\\"'))\n  File \"/usr/local/lib/python3.7/shlex.py\", line 309, in split\n    return list(lex)\n  File \"/usr/local/lib/python3.7/shlex.py\", line 299, in __next__\n    token = self.get_token()\n  File \"/usr/local/lib/python3.7/shlex.py\", line 109, in get_token\n    raw = self.read_token()\n  File \"/usr/local/lib/python3.7/shlex.py\", line 191, in read_token\n    raise ValueError(\"No closing quotation\")\nValueError: No closing quotation\n"
}

And I don't really understand how to use the API mentioned by @snowlucas
Edit: I have 3 servers with the same version of Freenas so I created a dummy rsync task called aaa on another server and the response gave the ID mentioned above. It doesen't help me with the problem but it shows that the API is working when all things are setup correct so I would classify this as a bug.
Heres the output of the API for the dummy task 'aaa'

Code:

[
{
  "id": 1,
  "path": "/mnt/P2/roland",
  "remotehost": "192.168.2.232",
  "remoteport": 22,
  "mode": "MODULE",
  "remotemodule": "aaa",
  "remotepath": "",
  "direction": "PUSH",
  "desc": "",
  "user": "root",
  "recursive": true,
  "times": true,
  "compress": true,
  "archive": false,
  "delete": false,
  "quiet": false,
  "preserveperm": false,
  "preserveattr": false,
  "delayupdates": true,
  "extra": [],
  "enabled": true,
  "schedule": {
   "minute": "0",
   "hour": "0",
   "dom": "1",
   "month": "*",
   "dow": "*"
  },
  "job": {
   "id": 5575,
   "method": "rsynctask.run",
   "arguments": [
    1
   ],
   "logs_path": "/tmp/middlewared/jobs/5575.log",
   "logs_excerpt": "rsync: rsync_xal_set: lsetxattr(\"/mnt/test\",\"DOSATTRIB\") failed: Operation not supported (45)\nrsync: rsync_xal_set: lsetxattr(\"/mnt/test/.21_15.txt.8JnOgD\",\"DOSATTRIB\") failed: Operation not supported (45)\nrsync: rsync_xal_set: lsetxattr(\"/mnt/test/Nytt textdokument.txt\",\"DOSATTRIB\") failed: Operation not supported (45)\nrsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1673) [generator=3.1.3]\n",
   "progress": {
    "percent": null,
    "description": null,
    "extra": null
   },
   "result": null,
   "error": "[EFAULT] rsync command returned 23. Check logs for further information.",
   "exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/job.py\", line 349, in run\n    await self.future\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/job.py\", line 388, in __run_body\n    rv = await self.middleware.run_in_thread(self.method, *([self] + args))\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/utils/run_in_thread.py\", line 10, in run_in_thread\n    return await self.loop.run_in_executor(self.run_in_thread_executor, functools.partial(method, *args, **kwargs))\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/utils/io_thread_pool_executor.py\", line 25, in run\n    result = self.fn(*self.args, **self.kwargs)\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/schema.py\", line 965, in nf\n    return f(*args, **kwargs)\n  File \"/usr/local/lib/python3.7/site-packages/middlewared/plugins/rsync.py\", line 605, in run\n    f'rsync command returned {cp.returncode}. Check logs for further information.'\nmiddlewared.service_exception.CallError: [EFAULT] rsync command returned 23. Check logs for further information.\n",
   "exc_info": {
    "type": "CallError",
    "extra": null
   },
   "state": "FAILED",
   "time_started": {
    "$date": 1591816576781
   },
   "time_finished": {
    "$date": 1591816582858
   }
  }
}
]

Any tip on how to solve this issue?
Is it a bug or just not a user friendly GUI?

Some hints on correct syntax for creating log files with timestamp in the file name is also most welcome.

 

[Samuel Tai]

Try it without the " in front of curl.

 

[·HeRmAN·]

Sorry about that, there was no " before curl.
And as I edited my post the API work on a different server

 

[Patrick M. Hausen]

@Samuel Tai I get what you are doing - can't you achieve the same more easily with midclt?

 

[·HeRmAN·]

The hints from @Samuel Tai was helpful after all.

Since I'm just starting up to use rsync to backup my home server to my almost identical backup server in a different location I only had two rsync tasks so deleting them both solved the issue.

Code:

root@S1[~]# curl --basic -u root -k -X DELETE "https://192.168.2.230/api/v2.0/rsynctask/id/2" -H "accept: */*"
Enter host password for user 'root':
true#
root@S1[~]# curl --basic -u root -k -X DELETE "https://192.168.2.230/api/v2.0/rsynctask/id/1" -H "accept: */*"
Enter host password for user 'root':
true#
root@S1[~]# 

Doing the task again is just good training.
Hints on the syntax for the creation of the file names is still most welcome.
And from now on I will run the API after each good created task to get the ID's documented in case of this happens again.
Thanks for the help!

 

[Samuel Tai]

@Samuel Tai I get what you are doing - can't you achieve the same more easily with midclt?

Midclt is much less well documented than the API.