User provisioning API response - wrong status code

[MercierCorentin]

Steps to reproduce and expected behavior are based on Nextcloud Provisioning API documentation

Steps to reproduce

1. Install a new nextcloud instance without email configuration.
2. Type the folowing command:

curl -X POST https://admin:password@domain.com/ocs/v1.php/cloud/users -d userid="username" -d password="C0mplic4tedpa$$w0rd" -d email="username@domain.com" -H "OCS-APIRequest: true"

Expected behaviour

STDOUT :

<?xml version="1.0"?>
<ocs>
 <meta>
 <statuscode>109</statuscode>
 <message>Unable to send the invitation mail</message>
 <totalitems></totalitems>
 <itemsperpage></itemsperpage>
 </meta>
 <data/>
</ocs>

Actual behaviour

We can see in the nextcloud logs that the error is correctly handled but the response status code is wrong.
STDOUT :

<?xml version="1.0"?>
<ocs>
 <meta>
 <status>failure</status>
 <statuscode>101</statuscode>
 <message>Bad request</message>
 <totalitems></totalitems>
 <itemsperpage></itemsperpage>
 </meta>
 <data/>
</ocs>

Server configuration

Operating system: Debian GNU/Linux 9.9 (stretch)

Web server: Apache

Database: PostgreSQL 11.3

PHP version: 7.3.6

Nextcloud version: 16.0.1.1 (Fresh install)

Signing status:

Signing status

No errors have been found.

List of activated apps:

App list

Enabled:
 - accessibility: 1.2.0
 - activity: 2.9.1
 - cloud_federation_api: 0.2.0
 - comments: 1.6.0
 - dav: 1.9.2
 - federatedfilesharing: 1.6.0
 - federation: 1.6.0
 - files: 1.11.0
 - files_pdfviewer: 1.5.0
 - files_rightclick: 0.13.0
 - files_sharing: 1.8.0
 - files_texteditor: 2.8.0
 - files_trashbin: 1.6.0
 - files_versions: 1.9.0
 - files_videoplayer: 1.5.0
 - firstrunwizard: 2.5.0
 - gallery: 18.3.0
 - logreader: 2.1.0
 - lookup_server_connector: 1.4.0
 - nextcloud_announcements: 1.5.0
 - notifications: 2.4.1
 - oauth2: 1.4.2
 - password_policy: 1.6.0
 - privacy: 1.0.0
 - provisioning_api: 1.6.0
 - recommendations: 0.4.0
 - serverinfo: 1.6.0
 - sharebymail: 1.6.0
 - support: 1.0.0
 - survey_client: 1.4.0
 - systemtags: 1.6.0
 - theming: 1.7.0
 - twofactor_backupcodes: 1.5.0
 - updatenotification: 1.6.0
 - viewer: 1.0.0
 - workflowengine: 1.6.0
Disabled:
 - admin_audit
 - encryption
 - files_external
 - user_ldap

Nextcloud configuration:

Config report

{
 "system": {
 "htaccess.RewriteBase": "\/",
 "memcache.local": "\\OC\\Memcache\\APCu",
 "apps_paths": [
 {
 "path": "\/var\/www\/html\/apps",
 "url": "\/apps",
 "writable": false
 },
 {
 "path": "\/var\/www\/html\/custom_apps",
 "url": "\/custom_apps",
 "writable": true
 }
 ],
 "passwordsalt": "***REMOVED SENSITIVE VALUE***",
 "secret": "***REMOVED SENSITIVE VALUE***",
 "trusted_domains": [
 "localhost",
 "localhost",
 "***REMOVED SENSITIVE VALUE***"
 ],
 "datadirectory": "***REMOVED SENSITIVE VALUE***",
 "dbtype": "pgsql",
 "version": "16.0.1.1",
 "overwrite.cli.url": "http:\/\/localhost",
 "dbname": "***REMOVED SENSITIVE VALUE***",
 "dbhost": "***REMOVED SENSITIVE VALUE***",
 "dbport": "",
 "dbtableprefix": "",
 "dbuser": "***REMOVED SENSITIVE VALUE***",
 "dbpassword": "***REMOVED SENSITIVE VALUE***",
 "installed": true,
 "instanceid": "***REMOVED SENSITIVE VALUE***"
 }
}

Logs

Web server error log

Web server error log

***IP ADDRESS*** - admin [13/Jun/2019:09:46:56 +0000] "POST /ocs/v1.php/cloud/users HTTP/1.1" 200 1422 "-" "curl/7.58.0"

Nextcloud log (data/nextcloud.log)

Nextcloud log

{"reqId":"SsG6ZLI8Ndva3TVaTv7P","level":3,"time":"2019-06-13T09:53:56+00:00","remoteAddr":"77.0.184.172","user":"admin","app":"ocs_api","method":"POST","url":"\/ocs\/v1.php\/cloud\/users","message":{"Exception":"Swift_TransportException","Message":"Connection could not be established with host 127.0.0.1 [Connection refused #111]","Code":0,"Trace":[{"file":"\/var\/www\/html\/3rdparty\/swiftmailer\/swiftmailer\/lib\/classes\/Swift\/Transport\/StreamBuffer.php","line":58,"function":"establishSocketConnection","class":"Swift_Transport_StreamBuffer","type":"->","args":[]},{"file":"\/var\/www\/html\/3rdparty\/swiftmailer\/swiftmailer\/lib\/classes\/Swift\/Transport\/AbstractSmtpTransport.php","line":143,"function":"initialize","class":"Swift_Transport_StreamBuffer","type":"->","args":[{"protocol":"*** sensitive parameter replaced ***","host":"127.0.0.1","port":25,"timeout":10,"blocking":1,"tls":false,"type":1,"stream_context_options":"*** sensitive parameter replaced ***"}]},{"file":"\/var\/www\/html\/3rdparty\/swiftmailer\/swiftmailer\/lib\/classes\/Swift\/Mailer.php","line":65,"function":"start","class":"Swift_Transport_AbstractSmtpTransport","type":"->","args":[]},{"file":"\/var\/www\/html\/lib\/private\/Mail\/Mailer.php","line":180,"function":"send","class":"Swift_Mailer","type":"->","args":[{"__class__":"Swift_Message"},"*** sensitive parameter replaced ***"]},{"file":"\/var\/www\/html\/settings\/Mailer\/NewUserMailHelper.php","line":169,"function":"send","class":"OC\\Mail\\Mailer","type":"->","args":[{"__class__":"OC\\Mail\\Message"}]},{"file":"\/var\/www\/html\/apps\/provisioning_api\/lib\/Controller\/UsersController.php","line":307,"function":"sendMail","class":"OC\\Settings\\Mailer\\NewUserMailHelper","type":"->","args":[{"__class__":"OC\\User\\User"},{"__class__":"OC\\Mail\\EMailTemplate"}]},{"file":"\/var\/www\/html\/lib\/private\/AppFramework\/Http\/Dispatcher.php","line":166,"function":"addUser","class":"OCA\\Provisioning_API\\Controller\\UsersController","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"\/var\/www\/html\/lib\/private\/AppFramework\/Http\/Dispatcher.php","line":99,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Provisioning_API\\Controller\\UsersController"},"addUser"]},{"file":"\/var\/www\/html\/lib\/private\/AppFramework\/App.php","line":126,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Provisioning_API\\Controller\\UsersController"},"addUser"]},{"file":"\/var\/www\/html\/lib\/private\/AppFramework\/Routing\/RouteActionHandler.php","line":47,"function":"main","class":"OC\\AppFramework\\App","type":"::","args":["OCA\\Provisioning_API\\Controller\\UsersController","addUser",{"__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"},{"_route":"ocs.provisioning_api.Users.addUser"}]},{"function":"__invoke","class":"OC\\AppFramework\\Routing\\RouteActionHandler","type":"->","args":[{"_route":"ocs.provisioning_api.Users.addUser"}]},{"file":"\/var\/www\/html\/lib\/private\/Route\/Router.php","line":297,"function":"call_user_func","args":[{"__class__":"OC\\AppFramework\\Routing\\RouteActionHandler"},{"_route":"ocs.provisioning_api.Users.addUser"}]},{"file":"\/var\/www\/html\/ocs\/v1.php","line":82,"function":"match","class":"OC\\Route\\Router","type":"->","args":["\/ocsapp\/cloud\/users"]}],"File":"\/var\/www\/html\/3rdparty\/swiftmailer\/swiftmailer\/lib\/classes\/Swift\/Transport\/StreamBuffer.php","Line":269,"CustomMessage":"Can't send new user mail to username@domain.com"},"userAgent":"curl\/7.58.0","version":"16.0.1.1"}
{"reqId":"SsG6ZLI8Ndva3TVaTv7P","level":3,"time":"2019-06-13T09:53:56+00:00","remoteAddr":"77.0.184.172","user":"admin","app":"ocs_api","method":"POST","url":"\/ocs\/v1.php\/cloud\/users","message":{"Exception":"OCP\\AppFramework\\OCS\\OCSException","Message":"Unable to send the invitation mail","Code":109,"Trace":[{"file":"\/var\/www\/html\/lib\/private\/AppFramework\/Http\/Dispatcher.php","line":166,"function":"addUser","class":"OCA\\Provisioning_API\\Controller\\UsersController","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"\/var\/www\/html\/lib\/private\/AppFramework\/Http\/Dispatcher.php","line":99,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Provisioning_API\\Controller\\UsersController"},"addUser"]},{"file":"\/var\/www\/html\/lib\/private\/AppFramework\/App.php","line":126,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Provisioning_API\\Controller\\UsersController"},"addUser"]},{"file":"\/var\/www\/html\/lib\/private\/AppFramework\/Routing\/RouteActionHandler.php","line":47,"function":"main","class":"OC\\AppFramework\\App","type":"::","args":["OCA\\Provisioning_API\\Controller\\UsersController","addUser",{"__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"},{"_route":"ocs.provisioning_api.Users.addUser"}]},{"function":"__invoke","class":"OC\\AppFramework\\Routing\\RouteActionHandler","type":"->","args":[{"_route":"ocs.provisioning_api.Users.addUser"}]},{"file":"\/var\/www\/html\/lib\/private\/Route\/Router.php","line":297,"function":"call_user_func","args":[{"__class__":"OC\\AppFramework\\Routing\\RouteActionHandler"},{"_route":"ocs.provisioning_api.Users.addUser"}]},{"file":"\/var\/www\/html\/ocs\/v1.php","line":82,"function":"match","class":"OC\\Route\\Router","type":"->","args":["\/ocsapp\/cloud\/users"]}],"File":"\/var\/www\/html\/apps\/provisioning_api\/lib\/Controller\/UsersController.php","Line":314,"CustomMessage":"Failed addUser attempt with exception."},"userAgent":"curl\/7.58.0","version":"16.0.1.1"}

[kesselb]

The right exception is thrown here

server/apps/provisioning_api/lib/Controller/UsersController.php

Line 314 in 45110f4

throw new OCSException('Unable to send the invitation mail', 109);

but catched later and changed to a bad request

server/apps/provisioning_api/lib/Controller/UsersController.php

Lines 327 to 334 in 45110f4

	} catch (\Exception $e) {
	$this->logger->logException($e, [
	'message' => 'Failed addUser attempt with exception.',
	'level' => ILogger::ERROR,
	'app' => 'ocs_api',
	]);
	throw new OCSException('Bad request', 101);
	}

Index: apps/provisioning_api/lib/Controller/UsersController.php
IDEA additional info:
Subsystem: com.intellij.openapi.diff.impl.patch.CharsetEP
<+>UTF-8
===================================================================
--- apps/provisioning_api/lib/Controller/UsersController.php	(revision 452d7696ff7e663f1794742d9708bb62a2771097)
+++ apps/provisioning_api/lib/Controller/UsersController.php	(date 1560626844000)
@@ -324,6 +324,13 @@
 				'app' => 'ocs_api',
 			]);
 			throw new OCSException($e->getHint(), 107);
+		} catch (OCSException $e) {
+			$this->logger->logException($e, [
+				'message' => 'Failed addUser attempt with ocs exeption.',
+				'level' => ILogger::ERROR,
+				'app' => 'ocs_api',
+			]);
+			throw $e;
 		} catch (\Exception $e) {
 			$this->logger->logException($e, [
 				'message' => 'Failed addUser attempt with exception.',

Mind to test this patch?

[kesselb]

cc @rullzer @MorrisJobke is this a bug or intended behaviour (like don't expose internals)?

[MercierCorentin]

Mind to test this patch?

@kesselb this patch worked fine for me. I ran some homemade tests on the user provisionning API (With and without mail configuration) and they all passed.
Is there something I can do to help?