Why "operation cancelled"?

vasyugan · September 12, 2017, 8:24pm

Nextcloud version: 12.0.2
Operating system and version (eg, Ubuntu 16.04): Ubuntu 16.04
Apache or nginx version (eg, Apache 2.4.25): Nginx 10.0.1
PHP version (eg, 5.6): 7.0
PHP 7.0-fpm 7.0.15
Is this the first time you’ve seen this error?: No

Can you reliably replicate it? (If so, please outline steps):

Issue occurs with certain files, but there is no way for me of predicting with which files it does.

The issue you are facing:

Files are uploaded incompletely. The sync client tries again and again, but keeps failing, while for all other files, things work just fine.

The output of your Nextcloud log in Admin > Logging:
{“reqId”:“A8Oi41piJLqQHFDU3ZNe”,“level”:4,“time”:“2017-09-12T20:00:28+00:00”,“remoteAddr”:“79.199.244.121”,“user”:“peter”,“app”:“webdav”,“method”:“PUT”,“url”:"/remote.php/dav/files/peter/Uferwerk_Vorstand/Finanzen/Rechnungen/170824_170911_Bauwerker_Baugesellschaft_Halle36_Trockenbau_Profile_etc_bezahlt_170912.pdf",“message”:“Exception: {“Exception”:“Sabre\\DAV\\Exception\\BadRequest”,“Message”:“expected filesize 1502979 got 65536”,“Code”:0,“Trace”:”#0 \/var\/www\/chrooted\/jrweb\/htdocs\/cloud.xxx.org\/apps\/dav\/lib\/Connector\/Sabre\/Directory.php(151): OCA\\DAV\\Connector\\Sabre\\File->put(Resource id #29)\n#1 \/var\/www\/chrooted\/jrweb\/htdocs\/cloud.xxx.org\/3rdparty\/sabre\/dav\/lib\/DAV\/Server.php(1096): OCA\\DAV\\Connector\\Sabre\\Directory->createFile(‘170824_170911_B…’, Resource id #29)\n#2 \/var\/www\/chrooted\/jrweb\/htdocs\/cloud.xxx.org\/3rdparty\/sabre\/dav\/lib\/DAV\/CorePlugin.php(525): Sabre\\DAV\\Server->createFile(‘files\/peter\/Ufe…’, Resource id #29, NULL)\n#3 [internal function]: Sabre\\DAV\\CorePlugin->httpPut(Object(Sabre\\HTTP\\Request), Object(Sabre\\HTTP\\Response))\n#4 \/var\/www\/chrooted\/jrweb\/htdocs\/cloud.xxx.org\/3rdparty\/sabre\/event\/lib\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\n#5 \/var\/www\/chrooted\/jrweb\/htdocs\/cloud.xxx.org\/3rdparty\/sabre\/dav\/lib\/DAV\/Server.php(479): Sabre\\Event\\EventEmitter->emit(‘method:PUT’, Array)\n#6 \/var\/www\/chrooted\/jrweb\/htdocs\/cloud.xxx.org\/3rdparty\/sabre\/dav\/lib\/DAV\/Server.php(254): Sabre\\DAV\\Server->invokeMethod(Object(Sabre\\HTTP\\Request), Object(Sabre\\HTTP\\Response))\n#7 \/var\/www\/chrooted\/jrweb\/htdocs\/cloud.xxx.org\/apps\/dav\/lib\/Server.php(253): Sabre\\DAV\\Server->exec()\n#8 \/var\/www\/chrooted\/jrweb\/htdocs\/cloud.xxx.org\/apps\/dav\/appinfo\/v2\/remote.php(33): OCA\\DAV\\Server->exec()\n#9 \/var\/www\/chrooted\/jrweb\/htdocs\/cloud.xxx.org\/remote.php(162): require_once(’\/var\/www\/chroot…’)\n#10 {main}",“File”:"\/var\/www\/chrooted\/jrweb\/htdocs\/cloud.xxx.org\/apps\/dav\/lib\/Connector\/Sabre\/File.php",“Line”:151}",“userAgent”:"Mozilla/5.0 (Windows) mirall/2.3.2 (build 1)

The output of your config.php file in /path/to/nextcloud (make sure you remove any identifiable information!):

<?php
$CONFIG = array (
  'instanceid' => 'XXXXXX',
  'passwordsalt' => '**',
  'datadirectory' => '**',
  'cron.lockfile.location' => '***',
  'dbtype' => 'mysql',
  'version' => '12.0.2.0',
  'dbname' => '****',
  'dbhost' => 'localhost',
  'dbtableprefix' => 'oc_',
  'dbuser' => '*****',
  'dbpassword' => '****',
  'installed' => true,
  'forcessl' => true,
  'maxZipInputSize' => 838860800,
  'allowZipDownload' => true,
  'theme' => '',
  'mail_smtpmode' => 'php',
  'mail_smtphost' => '127.0.0.1',
  'mail_smtpport' => 25,
  'mail_smtptimeout' => 10,
  'mail_smtpsecure' => '',
  'mail_smtpauth' => false,
  'mail_smtpauthtype' => 'LOGIN',
  'mail_smtpname' => '',
  'mail_smtppassword' => '',
  'trusted_domains' => 
  array (
    0 => '****',
    1 => '****',
    2 => '******',
    3 => '*****',
    4 => '******',
    ),
  'loglevel' => 2,
  'secret' => '******',
  'forceSSLforSubdomains' => false,
  'memcache.local' => '\\OC\\Memcache\\APCu',
  'maintenance' => false,
  'appstore.experimental.enabled' => true,
  'trashbin_retention_obligation' => 'auto',
  'updater.release.channel' => 'stable',
  'overwrite.cli.url' => '******',
);

The output of your Apache/nginx/system log in /var/log/____:

/the error log:/

rk_Vorstand/Finanzen/Rechnungen HTTP/1.1", upstream: "fastcgi://unix:/run/php/php7.0-fpm.sock:", host: "owncloud.uferwerk.org"
2017/09/12 22:15:09 [warn] 31459#31459: *12757304 an upstream response is buffered to a temporary file /var/lib/nginx/fastcgi/3/95/0000068953 while reading upstream, client: 79.199.247.212, server: cloud.xxx.org, request: "GET /remote.php/dav/files/tilman/Uferwerk_Hausverwaltung/Nutzungsvertr%C3%A4ge/Nutzungsvertr%C3%A4ge%20unterschrieben/Nutzungsvertrag_42.1.5_2017-06-06_Katharina_Bogatzky_Peter_Gro%C3%9Fmann.pdf HTTP/1.1", upstream: "fastcgi://unix:/run/php/php7.0-fpm.sock:", host: "owncloud.uferwerk.org"
2017/09/12 22:15:45 [warn] 31456#31456: *12763495 an upstream response is buffered to a temporary file /var/lib/nginx/fastcgi/4/95/0000068954 while reading upstream, client: 79.199.244.121, server: cloud.xxx.org, request: "PROPFIND /remote.php/dav/files/peter/Uferwerk_Vorstand/Finanzen/Rechnungen HTTP/1.1", upstream: "fastcgi://unix:/run/php/php7.0-fpm.sock:", host: "owncloud.uferwerk.org"
2017/09/12 22:20:22 [warn] 31455#31455: *12763920 an upstream response is buffered to a temporary file /var/lib/nginx/fastcgi/8/95/0000068958 while reading upstream, client: 79.199.244.121, server: cloud.xxx.org, request: "PROPFIND /remote.php/dav/files/peter/Uferwerk_Vorstand/Finanzen/Rechnungen HTTP/1.1", upstream: "fastcgi://unix:/run/php/php7.0-fpm.sock:", host: "owncloud.uferwerk.org"
2017/09/12 22:21:43 [warn] 31460#31460: *12765599 an upstream response is buffered to a temporary file /var/lib/nginx/fastcgi/1/96/0000068961 while reading upstream, client: 79.199.244.121, server: cloud.xxx.org, request: "PROPFIND /remote.php/dav/files/peter/Uferwerk_Vorstand/Finanzen/Rechnungen HTTP/1.1", upstream: "fastcgi://unix:/run/php/php7.0-fpm.sock:", host: "owncloud.uferwerk.org"
jr@ida:~/www/logs⟫

/the access log/

.0" 207 8703    "-" "Thunderbird CardBook/21.8 Lightning/5.4.3"    "-"
  79.199.244.121 - peter [12/Sep/2017:22:23:03 +0200]    "PROPFIND /remote.php/dav/files/peter/ HTTP/1.1" 207 1247    "-" "Mozilla/5.0 (Windows) mirall/2.3.2 (build 1) (Nextcloud)"    "-"
  79.199.244.121 - peter [12/Sep/2017:22:23:06 +0200]    "PROPFIND /remote.php/dav/files/peter/ HTTP/1.1" 207 1202    "-" "Mozilla/5.0 (Windows) mirall/2.3.2 (build 1) (Nextcloud)"    "-"
  79.199.244.121 - peter [12/Sep/2017:22:23:34 +0200]    "PROPFIND /remote.php/dav/files/peter/ HTTP/1.1" 207 1247    "-" "Mozilla/5.0 (Windows) mirall/2.3.2 (build 1) (Nextcloud)"    "-"
  79.199.244.121 - peter [12/Sep/2017:22:23:36 +0200]    "PROPFIND /remote.php/dav/files/peter/ HTTP/1.1" 207 1202    "-" "Mozilla/5.0 (Windows) mirall/2.3.2 (build 1) (Nextcloud)"    "-"
jr@ida:~/www/logs⟫

Remember, this information may be requested if it isn’t supplied; for fastest response please provide as much as you can Feel free to use a pastebin service, otherwise log files can be indented with 4 spaces on each line to present them in a friendlier way on the forum.

tflidd · September 16, 2017, 11:11pm

Can be upload limits, timeouts, buffering problems:

vasyugan · September 17, 2017, 8:00am

Do you have any suggestions how to narrow it down?

Isn’t there a way of more systematically finding out what it actually going wrong before blindly trying all the suggested fixed

vasyugan · September 17, 2017, 8:24pm

Just for you info, disabling the redis memcache fixes it. Which is a bit unfortunate, I would rather have redis enabled for performance reasons.

vasyugan · September 18, 2017, 8:38am

After all the error came back today, despite redis being disabled. Today I noticed a recurring message in the system log of the server about a bad block on the hard disk. I delete and reuploaded the file from another computer, after which the error was gone. The reason may or may not have been the bad block, which was now no longer used by the file