Bug 1538814

Summary: Imageio-Proxy: Failed to verify proxy ticket: Ticket life time expired
Product: [oVirt] ovirt-imageio Reporter: Gabriel <gabrielstein>
Component: ProxyAssignee: Daniel Erez <derez>
Status: CLOSED CURRENTRELEASE QA Contact: Avihai <aefrat>
Severity: high Docs Contact:
Priority: unspecified    
Version: 1.1.0CC: 729243088, amureini, bugs, ebenahar, fabiorauber, gabrielstein, ishaby, lveyde, tnisan, ylavi
Target Milestone: ovirt-4.2.2Flags: rule-engine: ovirt-4.2+
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: ovirt-engine-4.2.2 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-03-29 10:57:11 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Storage RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
VDSM from Node
none
SuperVDSM from Node
none
ImageIO Daemon from Node
none
Engine.log from Hosted Engine
none
ImageIO Proxy from Hosted Engine none

Description Gabriel 2018-01-25 21:45:25 UTC
Like Bug https://bugzilla.redhat.com/show_bug.cgi?id=1514887, but it wasn't solved on 4.2.

I'm using the Version 4.2.0 and uploading a 230GB Disk.

Question: How can I increase the timeout from client?

Log Error from Proxy:

<pre>
(Thread-20 ) ERROR root:Error starting session: Unable to verify proxy ticket
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/session.py", line 135, in start_session
    session_id = _create_update_session(ticket, session_id)
  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/session.py", line 194, in _create_update_session
    ticket_vars = _decode_proxy_ticket(authorization)
  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/session.py", line 237, in _decode_proxy_ticket
    payload = _decode_ovirt_ticket(ticket)
  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/session.py", line 315, in _decode_ovirt_ticket
    raise ValueError("Unable to verify proxy ticket")
ValueError: Unable to verify proxy ticket
(Thread-20 ) WARNING web:172.26.42.89 - PUT /16d4baa4-dfca-4f89-b594-20298443da9d 401 360 (0.00s)
172.26.42.89 - - [25/Jan/2018 22:29:57] "PUT /images/16d4baa4-dfca-4f89-b594-20298443da9d HTTP/1.1" 401 360
(Thread-21 ) INFO web:172.26.42.89 - OPTIONS /16d4baa4-dfca-4f89-b594-20298443da9d 204 0 (0.00s)
172.26.42.89 - - [25/Jan/2018 22:30:00] "OPTIONS /images/16d4baa4-dfca-4f89-b594-20298443da9d HTTP/1.1" 204 0
(Thread-22 ) ERROR root:Failed to verify proxy ticket: Ticket life time expired
(Thread-22 ) ERROR root:Error starting session: Unable to verify proxy ticket
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/session.py", line 135, in start_session
    session_id = _create_update_session(ticket, session_id)
  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/session.py", line 194, in _create_update_session
    ticket_vars = _decode_proxy_ticket(authorization)
  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/session.py", line 237, in _decode_proxy_ticket
    payload = _decode_ovirt_ticket(ticket)
  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/session.py", line 315, in _decode_ovirt_ticket
    raise ValueError("Unable to verify proxy ticket")
ValueError: Unable to verify proxy ticket
(Thread-22 ) WARNING web:172.26.42.89 - PUT /16d4baa4-dfca-4f89-b594-20298443da9d 401 360 (0.00s)
</pre>


Do you need more infos? vdsm.log? daemon.log?

Comment 1 Idan Shaby 2018-01-28 07:15:32 UTC
Hi Gebriel,

Yes, please attach full vdsm, engine, proxy and daemon logs so we can further investigate this bug.

Thanks!

Comment 2 Idan Shaby 2018-01-28 07:16:47 UTC
*Gabriel, sorry for the typo :)

Comment 3 Gabriel 2018-01-28 08:54:04 UTC
Hi!

No problem! I will do it again tomorrow at work and attach here all.

Thanks!!

Comment 4 Daniel Erez 2018-01-28 09:16:58 UTC
(In reply to Gabriel from comment #3)
> Hi!
> 
> No problem! I will do it again tomorrow at work and attach here all.
> 
> Thanks!!

Also, 

* Which version of proxy and engine are you using?
* Did you upload using the webadmin or the api/sdk?
* What are the complete steps you've followed to upload?
* Did you pause the upload during the transfer?

Thanks!

Comment 5 Gabriel 2018-01-28 09:39:27 UTC
(In reply to Daniel Erez from comment #4)
> (In reply to Gabriel from comment #3)
> > Hi!
> > 
> > No problem! I will do it again tomorrow at work and attach here all.
> > 
> > Thanks!!
> 
> Also, 
> 
> * Which version of proxy and engine are you using?
Proxy(package): 1.0.0-0.201701151456.git
Engine: 4.2.0.2-1
> * Did you upload using the webadmin or the api/sdk?
Webadmin
> * What are the complete steps you've followed to upload?
Webadmin>Storage>Disks>Upload.
> * Did you pause the upload during the transfer?
No.
> 
> Thanks!

I noticed that exactly after 1 hour of upload the timeout happens. I didnt founda way to change it.

One thing that is my problem, I'm running my storage connections with 10G cards and cables, but 1000G ports on switch. I will change it, probably helps making the upload on less time.

Thanks.

Comment 6 Daniel Erez 2018-01-28 09:55:38 UTC
(In reply to Gabriel from comment #5)
> (In reply to Daniel Erez from comment #4)
> > (In reply to Gabriel from comment #3)
> > > Hi!
> > > 
> > > No problem! I will do it again tomorrow at work and attach here all.
> > > 
> > > Thanks!!
> > 
> > Also, 
> > 
> > * Which version of proxy and engine are you using?
> Proxy(package): 1.0.0-0.201701151456.git
> Engine: 4.2.0.2-1
> > * Did you upload using the webadmin or the api/sdk?
> Webadmin
> > * What are the complete steps you've followed to upload?
> Webadmin>Storage>Disks>Upload.
> > * Did you pause the upload during the transfer?
> No.
> > 
> > Thanks!
> 
> I noticed that exactly after 1 hour of upload the timeout happens. I didnt
> founda way to change it.

The timeout is defined in ImageTransferClientTicketValidityInSeconds configuration value, which is 3600 seconds (can be altered in vdc_options table).
The ticket should have been extended automatically, but we had some issues
around this area in 4.2.0, so you can also try the update to latest version
and see if it mitigates the issue. Also, when ready, please upload full logs
for further investigation.


> 
> One thing that is my problem, I'm running my storage connections with 10G
> cards and cables, but 1000G ports on switch. I will change it, probably
> helps making the upload on less time.
> 
> Thanks.

Comment 7 Gabriel 2018-01-29 13:33:35 UTC
Created attachment 1387793 [details]
VDSM from Node

Comment 8 Gabriel 2018-01-29 13:34:06 UTC
Created attachment 1387795 [details]
SuperVDSM from Node

Comment 9 Gabriel 2018-01-29 13:34:37 UTC
Created attachment 1387796 [details]
ImageIO Daemon from Node

Comment 10 Gabriel 2018-01-29 13:35:08 UTC
Created attachment 1387797 [details]
Engine.log from Hosted Engine

Comment 11 Gabriel 2018-01-29 13:35:47 UTC
Created attachment 1387798 [details]
ImageIO Proxy from Hosted Engine

Comment 12 Gabriel 2018-01-29 13:37:39 UTC
OK, I attached everything as you asked.

After a yum update on hosted-engine, the results are the same, after 1 hour gave me a timeout.

Will be nice to solve it without some hacking on DB, because I'm afraid that will bring some problems on further updates.

Comment 13 Gabriel 2018-01-29 13:39:59 UTC
And yes, there is an error because I installed the packages from hosted engine on the node and I tried to add it as replica 4 with hyperconverged hosted-engine(no, it wasn't smart idea from me). As hyperconverged engine needs a replica 3, I just gave up, but I will remove the packages after...

Comment 14 Daniel Erez 2018-01-29 15:26:50 UTC
The suggested solutions by the patches:

* Expose 'ImageTransferClientTicketValidityInSeconds' key to engine-config so its value could be changed as follows:
# engine-config -s ImageTransferClientTicketValidityInSeconds=36000

* Increased the default value of ImageTransferClientTicketValidityInSeconds to 36000 seconds.

Also, note that it is recommended to upload a vast amount of data using the sdk:
https://github.com/oVirt/ovirt-engine-sdk/blob/master/sdk/examples/upload_disk.py

Comment 15 Gabriel 2018-01-29 18:37:36 UTC
Well, thank you. Using SDK  I had another two bugs, but I will create them properly. 

First using the SDK, he claims that my SSL certificate is invalid and them fails without removing the 'upload' from disk and I can't find and remove this disk using SDK or the webui..
 But as I said, another bugs. I will test this Patch and give you a feedback.


Thanks, you are awesome!

Comment 16 Gabriel 2018-01-29 19:04:55 UTC
I just didn't understand how to apply the patches.... at *.properties I could do a copy/paste from gerrit. And the sql file? Should I change it on postgres DB running on hosted-engine?

Thanks!

Comment 17 Daniel Erez 2018-01-29 19:27:15 UTC
* For the sdk, you should use the engine's ca.pem file, located at '/etc/pki/ovirt-engine'
* For the patches, you can just wait for the next build that includes them.

Comment 18 Avihai 2018-02-19 09:09:02 UTC
Verified on engine 4.2.2-0.1 .

Both get/set method in engine-config works OK :
- engine-config --set ImageTransferClientTicketValidityInSeconds=3600
- engine-config --get=ImageTransferClientTicketValidityInSeconds

Also, DB is updated in the vdc_options table as expected after setting a new value.

Comment 19 Sandro Bonazzola 2018-03-29 10:57:11 UTC
This bugzilla is included in oVirt 4.2.2 release, published on March 28th 2018.

Since the problem described in this bug report should be
resolved in oVirt 4.2.2 release, it has been closed with a resolution of CURRENT RELEASE.

If the solution does not work for you, please open a new bug report.