Bug 1372326 - disk remains locked after attempt to upload with ovirt-imageio-proxy functionality
Summary: disk remains locked after attempt to upload with ovirt-imageio-proxy function...
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: ovirt-engine
Classification: oVirt
Component: Frontend.WebAdmin
Version: 4.0.2
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ovirt-4.0.5
: ---
Assignee: Daniel Erez
QA Contact: Natalie Gavrielov
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-09-01 12:22 UTC by Gianluca Cecchi
Modified: 2016-09-13 07:38 UTC (History)
6 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2016-09-13 07:38:00 UTC
oVirt Team: Storage
Embargoed:
tnisan: ovirt-4.0.z?
rule-engine: planning_ack?
rule-engine: devel_ack?
rule-engine: testing_ack?


Attachments (Terms of Use)
disks pane in web admin gui (117.48 KB, image/png)
2016-09-01 12:22 UTC, Gianluca Cecchi
no flags Details
engine.log in gzip format (218.82 KB, application/x-gzip)
2016-09-01 12:23 UTC, Gianluca Cecchi
no flags Details

Description Gianluca Cecchi 2016-09-01 12:22:20 UTC
Created attachment 1196793 [details]
disks pane in web admin gui

Description of problem:
During upload of a disk image I had a problem with the target storage domain and the image remained as 'Locked'. This continues to remain true also after engine/host restart

Version-Release number of selected component (if applicable):
4.0.2

How reproducible:
donna

Steps to Reproduce:
1.
2. 
3.

Actual results:
The disk is in Locked state and I cannot do any operation on it.

Expected results:
A way to remove this stale object

Additional info:
I'm going to attach engine.log file. Th timestamp whan I tried upload of a disk with 'ppp' alias is '2016-08-26 16:44:18,752' inside the file.
I'm also going to upload screenshot of current view in disks pane.

Comment 1 Gianluca Cecchi 2016-09-01 12:23:26 UTC
Created attachment 1196794 [details]
engine.log in gzip format

Comment 2 Gianluca Cecchi 2016-09-01 13:53:28 UTC
Closed firefox from client and run engine-setup again:

Full output
[root@ractorshe tmp]# engine-setup --offline
[ INFO  ] Stage: Initializing
[ INFO  ] Stage: Environment setup
          Configuration files: ['/etc/ovirt-engine-setup.conf.d/10-packaging-jboss.conf', '/etc/ovirt-engine-setup.conf.d/10-packaging.conf', '/etc/ovirt-engine-setup.conf.d/20-setup-ovirt-post.conf']
          Log file: /var/log/ovirt-engine/setup/ovirt-engine-setup-20160901151651-n77p09.log
          Version: otopi-1.5.1 (otopi-1.5.1-1.el7.centos)
[ INFO  ] Stage: Environment packages setup
[ INFO  ] Stage: Programs detection
[ INFO  ] Stage: Environment setup
[ INFO  ] Stage: Environment customization
         
          --== PRODUCT OPTIONS ==--
         
         
          --== PACKAGES ==--
         
         
          --== NETWORK CONFIGURATION ==--
         
[WARNING] Failed to resolve ractorshe.mydomain using DNS, it can be resolved only locally
          Setup can automatically configure the firewall on this system.
          Note: automatic configuration of the firewall may overwrite current settings.
          Do you want Setup to configure the firewall? (Yes, No) [Yes]: 
[ INFO  ] firewalld will be configured as firewall manager.
         
          --== DATABASE CONFIGURATION ==--
         
          The detected DWH database size is 177 MB.
          Setup can backup the existing database. The time and space required for the database backup depend on its size. This process takes time, and in some cases (for instance, when the size is few GBs) may take several hours to complete.
          If you choose to not back up the database, and Setup later fails for some reason, it will not be able to restore the database and all DWH data will be lost.
          Would you like to backup the existing database before upgrading it? (Yes, No) [Yes]: 
         
          --== OVIRT ENGINE CONFIGURATION ==--
         
         
          --== STORAGE CONFIGURATION ==--
         
         
          --== PKI CONFIGURATION ==--
         
         
          --== APACHE CONFIGURATION ==--
         
         
          --== SYSTEM CONFIGURATION ==--
         
         
          --== MISC CONFIGURATION ==--
         
         
          --== END OF CONFIGURATION ==--
         
[ INFO  ] Stage: Setup validation
          During execution engine service will be stopped (OK, Cancel) [OK]: 
[ INFO  ] Hosted Engine HA is in Global Maintenance mode.
[ INFO  ] Cleaning stale zombie tasks and commands
         
          --== CONFIGURATION PREVIEW ==--
         
          Default SAN wipe after delete           : False
          Firewall manager                        : firewalld
          Update Firewall                         : True
          Host FQDN                               : ractorshe.mydomain
          Engine database secured connection      : False
          Engine database host                    : localhost
          Engine database user name               : engine
          Engine database name                    : engine
          Engine database port                    : 5432
          Engine database host name validation    : False
          DWH database secured connection         : False
          DWH database host                       : localhost
          DWH database user name                  : ovirt_engine_history
          DWH database name                       : ovirt_engine_history
          DWH database port                       : 5432
          DWH database host name validation       : False
          Engine installation                     : True
          PKI organization                        : mydomain
          DWH installation                        : True
          Backup DWH database                     : True
          Engine Host FQDN                        : ractorshe.mydomain
          Configure Image I/O Proxy               : True
          Configure VMConsole Proxy               : True
          Configure WebSocket Proxy               : True
         
          Please confirm installation settings (OK, Cancel) [OK]: 
[ INFO  ] Cleaning async tasks and compensations
[ INFO  ] Unlocking existing entities
[ INFO  ] Checking the Engine database consistency
[ INFO  ] Stage: Transaction setup
[ INFO  ] Stopping engine service
[ INFO  ] Stopping ovirt-fence-kdump-listener service
[ INFO  ] Stopping dwh service
[ INFO  ] Stopping Image I/O Proxy service
[ INFO  ] Stopping websocket-proxy service
[ INFO  ] Stage: Misc configuration
[ INFO  ] Stage: Package installation
[ INFO  ] Stage: Misc configuration
[ INFO  ] Upgrading CA
[ INFO  ] Backing up database localhost:engine to '/var/lib/ovirt-engine/backups/engine-20160901151715.I5SnB1.dump'.
[ INFO  ] Creating/refreshing Engine database schema
[ INFO  ] Backing up database localhost:ovirt_engine_history to '/var/lib/ovirt-engine-dwh/backups/dwh-20160901151750.SNeOmC.dump'.
[ INFO  ] Creating/refreshing DWH database schema
[ INFO  ] Configuring Image I/O Proxy
[ INFO  ] Configuring WebSocket Proxy
[ INFO  ] Creating/refreshing Engine 'internal' domain database schema
[ INFO  ] Generating post install configuration file '/etc/ovirt-engine-setup.conf.d/20-setup-ovirt-post.conf'
[ INFO  ] Stage: Transaction commit
[ INFO  ] Stage: Closing up
[ INFO  ] Starting engine service
[ INFO  ] Starting dwh service
[ INFO  ] Restarting ovirt-vmconsole proxy service
         
          --== SUMMARY ==--
         
[ INFO  ] Restarting httpd
          Web access is enabled at:
              http://ractorshe.mydomain:80/ovirt-engine
              https://ractorshe.mydomain:443/ovirt-engine
          Internal CA DA:E6:04:34:99:A0:DB:CE:3F:0A:7B:A2:96:67:4C:7F:19:CA:95:5F
          SSH fingerprint: 19:56:8d:3e:50:fc:90:37:5a:ba:6c:57:30:b1:7d:93
         
          --== END OF SUMMARY ==--
         
[ INFO  ] Stage: Clean up
          Log file is located at /var/log/ovirt-engine/setup/ovirt-engine-setup-20160901151651-n77p09.log
[ INFO  ] Generating answer file '/var/lib/ovirt-engine/setup/answers/20160901151815-setup.conf'
[ INFO  ] Stage: Pre-termination
[ INFO  ] Stage: Termination
[ INFO  ] Execution of setup completed successfully


Opened firefox in client and web console.
Still upload ends up in paused state.
I see localhost lines in web console output
I also see one line of kind
https://ractorshe.mydomain/ovirt-engine/services/reports-interface-proxy [HTTP/1.1 404 Not Found 89ms]
I donna if related to this problem tough...

This below is the full output of web console
          This site makes use of a SHA-1 Certificate; it's recommended you use certificates with signature algorithms that use hash functions stronger than SHA-1.[Learn More]ractorshe.mydomain
Thu Sep 01 15:23:42 GMT+200 2016 org.ovirt.engine.ui.common.uicommon.ContextSensitiveHelpManager
INFO: No context-sensitive help was found on the server. It will not be available for this session.webadmin:1:12954
Thu Sep 01 15:23:42 GMT+200 2016 org.ovirt.engine.ui.webadmin.plugin.PluginManager
INFO: Plugin [dashboard] has registered the event handler objectwebadmin:1:12954
Thu Sep 01 15:23:42 GMT+200 2016 org.ovirt.engine.ui.webadmin.plugin.PluginManager
INFO: Plugin [dashboard] reports in as readywebadmin:1:12954
Thu Sep 01 15:23:47 GMT+200 2016 org.ovirt.engine.ui.webadmin.plugin.PluginManager
INFO: Initializing plugin [dashboard]webadmin:1:12954
Thu Sep 01 15:23:47 GMT+200 2016 org.ovirt.engine.ui.webadmin.plugin.PluginManager
INFO: Invoking event handler function [UiInit] for plugin [dashboard]webadmin:1:12954
Thu Sep 01 15:23:47 GMT+200 2016 org.ovirt.engine.ui.webadmin.plugin.PluginManager
INFO: Plugin [dashboard] is initialized and in use nowwebadmin:1:12954
Thu Sep 01 15:23:47 GMT+200 2016 org.ovirt.engine.ui.webadmin.plugin.PluginManager
INFO: Invoking event handler function [UserLogin] for plugin [dashboard]webadmin:1:12954
Thu Sep 01 15:24:24 GMT+200 2016 
INFO: Polling for statuswebadmin:1:12954
Thu Sep 01 15:24:26 GMT+200 2016 
INFO: Upload phase: Initializingwebadmin:1:12954
Thu Sep 01 15:24:28 GMT+200 2016 
INFO: Polling for statuswebadmin:1:12954
Thu Sep 01 15:24:29 GMT+200 2016 
INFO: Upload phase: Initializingwebadmin:1:12954
Thu Sep 01 15:24:33 GMT+200 2016 
INFO: Polling for statuswebadmin:1:12954
Thu Sep 01 15:24:34 GMT+200 2016 
INFO: Upload phase: Transferringwebadmin:1:12954
"Thu Sep 01 15:24:34 GMT+200 2016 
INFO: Starting upload to https://localhost:54323/images
With imaged ticket: 1e06c843-6253-42be-a3a2-85c20bd0e48d
With proxy ticket: eyJzYWx0IjoidDVjczVQeGdDbDg9IiwiZGF0YSI6IntcbiAgXCJuYmZcIiA6IDE0NzI3MzYyNjYsXG4gIFwiZXhwXCIgOiAxNDcyNzM5ODY2LFxuICBcImlhdFwiIDogMTQ3MjczNjI2NixcbiAgXCJ0cmFuc2Zlci10aWNrZXRcIiA6IFwiMWUwNmM4NDMtNjI1My00MmJlLWEzYTItODVjMjBiZDBlNDhkXCIsXG4gIFwiaW1hZ2VkLXVyaVwiIDogXCJodHRwczovL3JhY3Rvci5kYXRhY2VudGVyLnBvbGltaS5pdDo1NDMyMlwiXG59Iiwic2lnbmF0dXJlIjoid0E1NDZvN1hRSDNpaURSUWF5VE5xQmFhYXgvMHhIdVpRVHV6d1MvdHlITG0zZnJyOFgyUk9wVG1FZHp6dkhhQW5sMWVOK1E3dUNBK1J3SC9PcDIyUHNOR01HY0p0cFNFVXVPTm1mM1RCWkw1MFg4MVpYSTkwSmM0QlZrWjdUVFVWTnV0ajE4amFpNHhwdWtvaVVJVGhKcUN5elcySm9hdzBLU1BITkVmaHQ3Uy9vQkFPMXBnS2dqVlE0RFdQcm5HZHZubTBhT1l2YkNoTDlJRXV2ZmdnbHAxbVprTVhSNkxXWW1xaXlMcVBwZ1VpVTl6RzgrMEJ3dytPQ0RwVE0rUXhhaVdpUTdBRFU2RDIyRjN3dVo2ZzJ5TkdTbGlQbXVHSXllb28raGkzcG5RbkRBdzNXVnJkVTdQOUhENmhaYmlYbEhkVyt3QWtpK2lUeU9LTHU3OXBRPT0iLCJkaWdlc3QiOiJzaGExIiwiY2VydGlmaWNhdGUiOiItLS0tLUJFR0lOIENFUlRJRklDQVRFLS0tLS1cbk1JSUVyVENDQTVXZ0F3SUJBZ0lDRUFFd0RRWUpLb1pJaHZjTkFRRUZCUUF3V3pFTE1Ba0dBMVVFQmhNQ1ZWTXhIVEFiQmdOVkJBb1RcclxuRkdSaGRHRmpaVzUwWlhJdWNHOXNhVzFwTG1sME1TMHdLd1lEVlFRREV5UnlZV04wYjNKemFHVXVaR0YwWVdObGJuUmxjaTV3YjJ4cFxyXG5iV2t1YVhRdU1UTTVPVGt3SGhjTk1UVXhNVEU0TVRRek16VTFXaGNOTWpBeE1ESXpNVFF6TXpVMVdqQlZNUXN3Q1FZRFZRUUdFd0pWXHJcblV6RWRNQnNHQTFVRUNoTVVaR0YwWVdObGJuUmxjaTV3YjJ4cGJXa3VhWFF4SnpBbEJnTlZCQU1USG5KaFkzUnZjbk5vWlM1a1lYUmhcclxuWTJWdWRHVnlMbkJ2YkdsdGFTNXBkRENDQVNJd0RRWUpLb1pJaHZjTkFRRUJCUUFEZ2dFUEFEQ0NBUW9DZ2dFQkFOd0E5cmc4cGNCR1xyXG5zeGpMZSs3UzhFeU9aRnloN1FOQjBDNnpqNGdKeUd6N1FyVVNMcFEwTUNlSjdrWlBuRTBuM1hGazg1NDM0anJpMkh3UlBBcUkwcFM2XHJcbkg5VGR1MGNubDZRNDkrbllTSTdaVjFyR25SYXlTZU55ZWNQRTh1blhSVlVPWWhHVkltSXIxVmxKTzc0V2tsL1F1aHYwTzZKZzQ4RElcclxuL3pPSGllU2tXVGpJVWtKSE1waTRNU3QyU29YZ0xnMXVpcUptZkxsM0tONGVYeXcrcVRPaytKRjJrTER3UU1waTZJUXp5REx2eVJjTFxyXG5lbDBQaE1MTDlMTWVPMVlJTFZCTFRxTXorb2tWWjJJZ1dSaXRGNkMwWjBjd0pCeGcxb1RENXVtZnloWi9kVEY1V2x3Q2VOQWRtUUFyXHJcbnpPUjZoV0lMMURBTmNEamMvUGFJT2d3cEE1TUNBd0VBQWFPQ0FYOHdnZ0Y3TUIwR0ExVWREZ1FXQkJTMUo5cm43Wjcramt6ZGl3MHpcclxuUnl4S0pRdFFoVENCbFFZSUt3WUJCUVVIQVFFRWdZZ3dnWVV3Z1lJR0NDc0dBUVVGQnpBQ2huWm9kSFJ3T2k4dmNtRmpkRzl5YzJobFxyXG5MbVJoZEdGalpXNTBaWEl1Y0c5c2FXMXBMbWwwT2pnd0wyOTJhWEowTFdWdVoybHVaUzl6WlhKMmFXTmxjeTl3YTJrdGNtVnpiM1Z5XHJcblkyVS9jbVZ6YjNWeVkyVTlZMkV0WTJWeWRHbG1hV05oZEdVbVptOXliV0YwUFZnMU1Ea3RVRVZOTFVOQk1JR0VCZ05WSFNNRWZUQjdcclxuZ0JTUkF0VkRmM0tqZnRXcE5qTFJ1MEwwMnRxZ3pLRmZwRjB3V3pFTE1Ba0dBMVVFQmhNQ1ZWTXhIVEFiQmdOVkJBb1RGR1JoZEdGalxyXG5aVzUwWlhJdWNHOXNhVzFwTG1sME1TMHdLd1lEVlFRREV5UnlZV04wYjNKemFHVXVaR0YwWVdObGJuUmxjaTV3YjJ4cGJXa3VhWFF1XHJcbk1UTTVPVG1DQWhBQU1Ba0dBMVVkRXdRQ01BQXdEZ1lEVlIwUEFRSC9CQVFEQWdXZ01DQUdBMVVkSlFFQi93UVdNQlFHQ0NzR0FRVUZcclxuQndNQkJnZ3JCZ0VGQlFjREFqQU5CZ2txaGtpRzl3MEJBUVVGQUFPQ0FRRUFrTWJyR01wU3JJalpaS1FsejN3bVgxM0paalJtbk5rV1xyXG5zVU1pVE1pL2tUeDdid0VUWlFWenc2WDZ1bUhXcXJBM1hyaC9raEZQcTNCcHArR2dSdGdyWnY1eUx1MXlmZk03Z1MrMWFqVEtrWjVvXHJcbkVlcnBUekRhV3lTYy9QWDNoQUpDNE0zdGlsdWVjNk9FYll2YkN0NEZJQnRnZUNMWW9CTFgrVzhoTXFibHFkVTFuNWJ5MkptWDQrYTlcclxuTzJ5TnpUNWhSR05NQ2xkRE03M2pJcjVITCtPMjh2dkI0WHZHNkJGditxaHIzS0c5aWV2eDdqN3A3VEo0Tlc0ZFNWd01xMUZtZmJRc1xyXG5nVTlhYWpaRGZiSUhRdVdMN1JnWEFXM1IvbGdRUnAxa094NHFVZlZqZWh3dE9FTzJON1p0aWxnbWt2ZVZoRVlwdFRVb1djVTAyWUZvXHJcbkxzVXNadz09XHJcbi0tLS0tRU5EIENFUlRJRklDQVRFLS0tLS1cbiIsInNpZ25lZEZpZWxkcyI6InNhbHQsZGF0YSxkaWdlc3QsdmFsaWRGcm9tLHZhbGlkVG8iLCJ2YWxpZEZyb20iOiIyMDE2MDkwMTEzMjQyNiIsInZhbGlkVG8iOiIyMDE2MDkwMTE0MjQyNiJ9"webadmin:1:12954
Thu Sep 01 15:24:34 GMT+200 2016 
INFO: doUpload: Starting at byte 0webadmin:1:12954
"Thu Sep 01 15:24:34 GMT+200 2016 
INFO: doUpload: Selected file: manageiq_01.qcow2 (size: 1677787136 bytes)"webadmin:1:12954
"Thu Sep 01 15:24:34 GMT+200 2016 
INFO: sendChunk: PUT https://localhost:54323/images/1e06c843-6253-42be-a3a2-85c20bd0e48d bytes 0-8388607/1677787136"webadmin:1:12954
Thu Sep 01 15:24:36 GMT+200 2016 
SEVERE: xhrHandle: Status: 0, text: , response: webadmin:1:12869

Thu Sep 01 15:24:36 GMT+200 2016 
SEVERE: xhrError: 0 webadmin:1:12869

Thu Sep 01 15:24:36 GMT+200 2016 
WARNING: xhrError: Retrying (attempt 1 of 3)webadmin:1:12912
Thu Sep 01 15:24:39 GMT+200 2016 
INFO: Polling for statuswebadmin:1:12954
Thu Sep 01 15:24:39 GMT+200 2016 
INFO: Upload phase: Transferringwebadmin:1:12954
"Thu Sep 01 15:24:41 GMT+200 2016 
INFO: sendChunk: PUT https://localhost:54323/images/1e06c843-6253-42be-a3a2-85c20bd0e48d bytes 0-8388607/1677787136"webadmin:1:12954
Thu Sep 01 15:24:44 GMT+200 2016 
SEVERE: xhrHandle: Status: 0, text: , response: webadmin:1:12869

Thu Sep 01 15:24:44 GMT+200 2016 
SEVERE: xhrError: 0 webadmin:1:12869

Thu Sep 01 15:24:44 GMT+200 2016 
WARNING: xhrError: Retrying (attempt 2 of 3)webadmin:1:12912
Thu Sep 01 15:24:44 GMT+200 2016 
INFO: Polling for statuswebadmin:1:12954
Thu Sep 01 15:24:44 GMT+200 2016 
INFO: Upload phase: Transferringwebadmin:1:12954
GET 
XHR 
https://ractorshe.mydomain/ovirt-engine/services/reports-interface-proxy [HTTP/1.1 404 Not Found 89ms]
"Thu Sep 01 15:24:47 GMT+200 2016 
INFO: sendChunk: PUT https://localhost:54323/images/1e06c843-6253-42be-a3a2-85c20bd0e48d bytes 0-8388607/1677787136"webadmin:1:12954
Thu Sep 01 15:24:48 GMT+200 2016 
INFO: Polling for statuswebadmin:1:12954
Thu Sep 01 15:24:49 GMT+200 2016 
SEVERE: xhrHandle: Status: 0, text: , response: webadmin:1:12869

Thu Sep 01 15:24:49 GMT+200 2016 
SEVERE: xhrError: 0 webadmin:1:12869

Thu Sep 01 15:24:49 GMT+200 2016 
WARNING: xhrError: Retrying (attempt 3 of 3)webadmin:1:12912
Thu Sep 01 15:24:49 GMT+200 2016 
INFO: Upload phase: Transferringwebadmin:1:12954
Thu Sep 01 15:24:53 GMT+200 2016 
INFO: Polling for statuswebadmin:1:12954
"Thu Sep 01 15:24:53 GMT+200 2016 
INFO: sendChunk: PUT https://localhost:54323/images/1e06c843-6253-42be-a3a2-85c20bd0e48d bytes 0-8388607/1677787136"webadmin:1:12954
Thu Sep 01 15:24:53 GMT+200 2016 
INFO: Upload phase: Transferringwebadmin:1:12954
Thu Sep 01 15:24:54 GMT+200 2016 
SEVERE: xhrHandle: Status: 0, text: , response: webadmin:1:12869

Thu Sep 01 15:24:54 GMT+200 2016 
SEVERE: xhrError: 0 webadmin:1:12869

Thu Sep 01 15:24:54 GMT+200 2016 
SEVERE: Transfer failed after 3/3 errorswebadmin:1:12869

Thu Sep 01 15:24:54 GMT+200 2016 
WARNING: Finalizing upload with status CLIENT_ERRORwebadmin:1:12912
Thu Sep 01 15:24:54 GMT+200 2016

Comment 3 Allon Mureinik 2016-09-04 12:53:40 UTC
Amit, didn't you resolve something similar in 4.0.3?

Comment 4 Amit Aviram 2016-09-04 13:24:37 UTC
No, in 4.0.3 we dealt with setup issues.

Comment 5 Gianluca Cecchi 2016-09-08 12:34:52 UTC
Just to notice that after applying changes in database with steps described here:
http://lists.ovirt.org/pipermail/users/2016-September/042461.html
the disk came back into OK state (actually the disk file doesn't exist at all).
But at least I was then able to delete it.
Previously the stop/start of the engine and/or of the ovirt-imageio-proxy services didn't change the status of the disk image file.
Let me know if you want further information.


Gianluca

Comment 6 Daniel Erez 2016-09-11 11:37:17 UTC
(In reply to Gianluca Cecchi from comment #5)
> Just to notice that after applying changes in database with steps described
> here:
> http://lists.ovirt.org/pipermail/users/2016-September/042461.html
> the disk came back into OK state (actually the disk file doesn't exist at
> all).
> But at least I was then able to delete it.
> Previously the stop/start of the engine and/or of the ovirt-imageio-proxy
> services didn't change the status of the disk image file.
> Let me know if you want further information.
> 
> 
> Gianluca

Hi Gianluca,

* Can you please attach also vdsm log and ovirt-imageio-proxy?
* You can unlock a disk using 'unlock_entity' utility: https://www.ovirt.org/develop/developer-guide/db-issues/helperutilities/
* So, IIUC, uploading works now as expected?

Thanks!

Comment 7 Gianluca Cecchi 2016-09-12 09:29:14 UTC
I'm going to attach the asked logs.
I confirm that after explicitly setting the image proxy hostname into the database with the statement: 
update vdc_options set option_value='ractorshe.mydomain:54323'
where option_name='ImageProxyAddress';

I was then able to upload new images.
Furthermore the locked one went into OK status (even if the image actually didn't exist at all on disk because I was not able to upload it...) so that I could then delete it.

Previously the option_value field in database contained "localhost:54323"

Comment 8 Gianluca Cecchi 2016-09-12 09:40:28 UTC
Unfortunately vdsm logs arrive back only to 8th of September (100 logs in total).
So I don't have anymore the log file for 1st of September when I was able to delete the image. 

For ovirt-imageio-proxy, until I was able to solve the upload problems, I got only these kind of messages inside image-proxy.log:

(MainThread) INFO 2016-08-30 14:49:48,421 image_proxy:35:root:(main) Server shut down, exiting
(MainThread) INFO 2016-08-30 14:49:48,633 image_proxy:26:root:(main) Server started, successfully notified systemd

nothing about operations

Instead, when on 1st of September I solved the problems with manual database entry, I have these kind of messages when I load an image:

(MainThread) INFO 2016-09-01 15:17:14,200 image_proxy:35:root:(main) Server shut down, exiting
(MainThread) INFO 2016-09-01 15:18:13,093 image_proxy:26:root:(main) Server started, successfully notified systemd
(MainThread) INFO 2016-09-01 15:36:11,497 image_proxy:35:root:(main) Server shut down, exiting
(MainThread) INFO 2016-09-01 15:36:11,704 image_proxy:26:root:(main) Server started, successfully notified systemd
(MainThread) INFO 2016-09-01 17:27:29,531 image_proxy:35:root:(main) Server shut down, exiting
(MainThread) INFO 2016-09-01 17:31:41,940 image_proxy:26:root:(main) Server started, successfully notified systemd
(MainThread) INFO 2016-09-01 17:45:48,929 image_proxy:35:root:(main) Server shut down, exiting
(MainThread) INFO 2016-09-01 17:46:39,109 image_proxy:26:root:(main) Server started, successfully notified systemd
(Thread-2  ) INFO 2016-09-01 17:55:56,347 session:259:root:(_decode_proxy_ticket) Proxy ticket valid: {u'iat': 1472745349, u'imaged-uri': u'https://ractor.mydomain:54322', u'nbf': 1472745349, u'exp': 1472748949, u'transfer-ticket': u'2ec98941-e290-43d8-8c2c-272dddfa056c'}
(Thread-2  ) INFO 2016-09-01 17:55:56,348 session:191:root:(_create_update_session) Established session: expiration: '1472748949', imaged-host-uri: 'https://ractor.mydomain:54322', proxy-ticket: 'eyJzYWx0IjoiaEZYL2UwZVZtbUU9IiwiZGF0YSI6IntcbiAgXCJuYmZcIiA6...OiIyMDE2MDkwMTE1NTU0OSIsInZhbGlkVG8iOiIyMDE2MDkwMTE2NTU0OSJ9', session-id: '75c1b0aa-e268-4bd5-b9e7-58bf50626445', transfer-ticket: '2ec98941-e290-43d8-8c2c-272dddfa056c'
(Thread-2  ) INFO 2016-09-01 17:55:56,364 connectionpool:735:requests.packages.urllib3.connectionpool:(_new_conn) Starting new HTTPS connection (1): ractor.mydomain
(Thread-3  ) INFO 2016-09-01 17:55:57,470 session:259:root:(_decode_proxy_ticket) Proxy ticket valid: {u'iat': 1472745349, u'imaged-uri': u'https://ractor.mydomain:54322', u'nbf': 1472745349, u'exp': 1472748949, u'transfer-ticket': u'2ec98941-e290-43d8-8c2c-272dddfa056c'}
(Thread-3  ) INFO 2016-09-01 17:55:57,470 session:191:root:(_create_update_session) Established session: expiration: '1472748949', imaged-host-uri: 'https://ractor.mydomain:54322', proxy-ticket: 'eyJzYWx0IjoiaEZYL2UwZVZtbUU9IiwiZGF0YSI6IntcbiAgXCJuYmZcIiA6...OiIyMDE2MDkwMTE1NTU0OSIsInZhbGlkVG8iOiIyMDE2MDkwMTE2NTU0OSJ9', session-id: 'd0ff6cc7-9d39-4cec-b4b3-63ec1729684c', transfer-ticket: '2ec98941-e290-43d8-8c2c-272dddfa056c'
(Thread-3  ) INFO 2016-09-01 17:55:57,472 connectionpool:735:requests.packages.urllib3.connectionpool:(_new_conn) Starting new HTTPS connection (1): ractor.mydomain
(Thread-4  ) INFO 2016-09-01 17:55:59,244 session:259:root:(_decode_proxy_ticket) Proxy ticket valid: {u'iat': 1472745349, u'imaged-uri': u'https://ractor.mydomain:54322', u'nbf': 1472745349, u'exp': 1472748949, u'transfer-ticket': u'2ec98941-e290-43d8-8c2c-272dddfa056c'}
...

Comment 9 Daniel Erez 2016-09-12 15:41:26 UTC
(In reply to Gianluca Cecchi from comment #7)
> I'm going to attach the asked logs.
> I confirm that after explicitly setting the image proxy hostname into the
> database with the statement: 
> update vdc_options set option_value='ractorshe.mydomain:54323'
> where option_name='ImageProxyAddress';
> 
> I was then able to upload new images.
> Furthermore the locked one went into OK status (even if the image actually
> didn't exist at all on disk because I was not able to upload it...) so that
> I could then delete it.
> 
> Previously the option_value field in database contained "localhost:54323"

@Amit - IIUC, this is merely a configuration issue? So as a future improvement, perhaps we could validate the ImageProxyAddress, do we have an open rfe for that?

Comment 10 Amit Aviram 2016-09-13 06:46:36 UTC
(In reply to Daniel Erez from comment #9)
> (In reply to Gianluca Cecchi from comment #7)
> > I'm going to attach the asked logs.
> > I confirm that after explicitly setting the image proxy hostname into the
> > database with the statement: 
> > update vdc_options set option_value='ractorshe.mydomain:54323'
> > where option_name='ImageProxyAddress';
> > 
> > I was then able to upload new images.
> > Furthermore the locked one went into OK status (even if the image actually
> > didn't exist at all on disk because I was not able to upload it...) so that
> > I could then delete it.
> > 
> > Previously the option_value field in database contained "localhost:54323"
> 
> @Amit - IIUC, this is merely a configuration issue? So as a future
> improvement, perhaps we could validate the ImageProxyAddress, do we have an
> open rfe for that?

I don't think it's valuable, the proxy address can be anything, including localhost. and when there's no connectivity with the given address, we now have a proper error message in the webadmin. So there's nothing really to validate.

Comment 11 Daniel Erez 2016-09-13 07:38:00 UTC
(In reply to Amit Aviram from comment #10)
> (In reply to Daniel Erez from comment #9)
> > (In reply to Gianluca Cecchi from comment #7)
> > > I'm going to attach the asked logs.
> > > I confirm that after explicitly setting the image proxy hostname into the
> > > database with the statement: 
> > > update vdc_options set option_value='ractorshe.mydomain:54323'
> > > where option_name='ImageProxyAddress';
> > > 
> > > I was then able to upload new images.
> > > Furthermore the locked one went into OK status (even if the image actually
> > > didn't exist at all on disk because I was not able to upload it...) so that
> > > I could then delete it.
> > > 
> > > Previously the option_value field in database contained "localhost:54323"
> > 
> > @Amit - IIUC, this is merely a configuration issue? So as a future
> > improvement, perhaps we could validate the ImageProxyAddress, do we have an
> > open rfe for that?
> 
> I don't think it's valuable, the proxy address can be anything, including
> localhost. and when there's no connectivity with the given address, we now
> have a proper error message in the webadmin. So there's nothing really to
> validate.

Per comment above, closing the issue as we now have a proper error message.


Note You need to log in before you can comment on or make changes to this bug.