Attachment 1474617 Details for Bug 1576500 – image proxy log

image proxy log

image-proxy.log (text/plain), 15.66 KB, created by Avihai on 2018-08-09 09:20:16 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Avihai

Created: 2018-08-09 09:20:16 UTC

Size: 15.66 KB

patch

obsolete

>(Thread-1  ) INFO 2018-08-08 10:38:41,250 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-2  ) INFO 2018-08-08 10:38:41,258 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-3  ) INFO 2018-08-08 10:38:41,264 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-4  ) INFO 2018-08-08 10:38:41,273 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-4  ) INFO 2018-08-08 10:38:41,312 auth:187:auth2:(add_signed_ticket) Adding new ticket: <Ticket id=u'8d795065-826a-4ae8-80f5-1c35fbb64090', url=u'https://lynx09.lab.eng.tlv2.redhat.com:54322' timeout=35997.68738389015 at 0x7fa6c3cba210>
>(Thread-4  ) INFO 2018-08-08 10:38:41,313 web:77:web:(close) FINISH [10.46.16.250] PUT /tickets/: [200] 0 [request=0.039486]
>(Thread-2  ) ERROR 2018-08-08 10:38:41,304 web:136:web:(log_error) ERROR [10.46.16.250] PUT /tickets/: [500] _strptime_time [request=0.046504]
>Traceback (most recent call last):
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 99, in __call__
>    resp = self.dispatch(request, clock)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 128, in dispatch
>    return method(*match.groups())
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/tickets.py", line 32, in put
>    auth.add_signed_ticket(self.request.body)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/auth.py", line 184, in add_signed_ticket
>    payload = _decode_ovirt_ticket(data)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/auth.py", line 231, in _decode_ovirt_ticket
>    return decoder.decode(data)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/ticket.py", line 94, in decode
>    self._verifyCertificate(self._ca, x509)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/ticket.py", line 70, in _verifyCertificate
>    x509.get_not_before().get_datetime().replace(tzinfo=None) <=
>  File "/usr/lib64/python2.7/site-packages/M2Crypto/ASN1.py", line 181, in get_datetime
>    tm = list(time.strptime(rest, "%d %H:%M:%S %Y"))[:6]
>AttributeError: _strptime_time
>(Thread-3  ) ERROR 2018-08-08 10:38:41,307 web:136:web:(log_error) ERROR [10.46.16.250] PUT /tickets/: [500] _strptime_time [request=0.042288]
>Traceback (most recent call last):
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 99, in __call__
>    resp = self.dispatch(request, clock)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 128, in dispatch
>    return method(*match.groups())
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/tickets.py", line 32, in put
>    auth.add_signed_ticket(self.request.body)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/auth.py", line 184, in add_signed_ticket
>    payload = _decode_ovirt_ticket(data)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/auth.py", line 231, in _decode_ovirt_ticket
>    return decoder.decode(data)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/ticket.py", line 94, in decode
>    self._verifyCertificate(self._ca, x509)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/ticket.py", line 70, in _verifyCertificate
>    x509.get_not_before().get_datetime().replace(tzinfo=None) <=
>  File "/usr/lib64/python2.7/site-packages/M2Crypto/ASN1.py", line 181, in get_datetime
>    tm = list(time.strptime(rest, "%d %H:%M:%S %Y"))[:6]
>AttributeError: _strptime_time
>(Thread-1  ) ERROR 2018-08-08 10:38:41,307 web:136:web:(log_error) ERROR [10.46.16.250] PUT /tickets/: [500] _strptime_time [request=0.057461]
>Traceback (most recent call last):
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 99, in __call__
>    resp = self.dispatch(request, clock)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_common/web.py", line 128, in dispatch
>    return method(*match.groups())
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/tickets.py", line 32, in put
>    auth.add_signed_ticket(self.request.body)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/auth.py", line 184, in add_signed_ticket
>    payload = _decode_ovirt_ticket(data)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/auth.py", line 231, in _decode_ovirt_ticket
>    return decoder.decode(data)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/ticket.py", line 94, in decode
>    self._verifyCertificate(self._ca, x509)
>  File "/usr/lib/python2.7/site-packages/ovirt_imageio_proxy/ticket.py", line 70, in _verifyCertificate
>    x509.get_not_before().get_datetime().replace(tzinfo=None) <=
>  File "/usr/lib64/python2.7/site-packages/M2Crypto/ASN1.py", line 181, in get_datetime
>    tm = list(time.strptime(rest, "%d %H:%M:%S %Y"))[:6]
>AttributeError: _strptime_time
>(Thread-5  ) INFO 2018-08-08 10:38:42,195 web:97:web:(__call__) START: [10.46.16.250] DELETE /tickets/8d795065-826a-4ae8-80f5-1c35fbb64090
>(Thread-5  ) INFO 2018-08-08 10:38:42,195 auth:201:auth2:(delete_ticket) Deleting ticket u'8d795065-826a-4ae8-80f5-1c35fbb64090'
>(Thread-5  ) INFO 2018-08-08 10:38:42,196 web:77:web:(close) FINISH [10.46.16.250] DELETE /tickets/8d795065-826a-4ae8-80f5-1c35fbb64090: [204] 0 [request=0.001079]
>(Thread-6  ) INFO 2018-08-08 10:43:37,787 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-6  ) INFO 2018-08-08 10:43:37,789 auth:187:auth2:(add_signed_ticket) Adding new ticket: <Ticket id=u'830d5e73-10ab-4886-be06-e0888d41c1cc', url=u'https://lynx10.lab.eng.tlv2.redhat.com:54322' timeout=35998.20999789238 at 0x7fa6c3cb2f50>
>(Thread-6  ) INFO 2018-08-08 10:43:37,790 web:77:web:(close) FINISH [10.46.16.250] PUT /tickets/: [200] 0 [request=0.002895]
>(Thread-7  ) INFO 2018-08-08 10:43:37,886 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-7  ) INFO 2018-08-08 10:43:37,888 auth:187:auth2:(add_signed_ticket) Adding new ticket: <Ticket id=u'0e2b345c-3a83-4c27-891d-913d9ae38368', url=u'https://lynx09.lab.eng.tlv2.redhat.com:54322' timeout=35998.11112689972 at 0x7fa6c3cb2f10>
>(Thread-7  ) INFO 2018-08-08 10:43:37,889 web:77:web:(close) FINISH [10.46.16.250] PUT /tickets/: [200] 0 [request=0.003154]
>(Thread-8  ) INFO 2018-08-08 10:43:38,089 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-8  ) INFO 2018-08-08 10:43:38,091 auth:187:auth2:(add_signed_ticket) Adding new ticket: <Ticket id=u'c993ad83-9ed2-4de0-a87d-05b4e69f63b3', url=u'https://lynx09.lab.eng.tlv2.redhat.com:54322' timeout=35998.907942056656 at 0x7fa6c3cb2d50>
>(Thread-8  ) INFO 2018-08-08 10:43:38,092 web:77:web:(close) FINISH [10.46.16.250] PUT /tickets/: [200] 0 [request=0.002844]
>(Thread-9  ) INFO 2018-08-08 10:43:38,330 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-9  ) INFO 2018-08-08 10:43:38,332 auth:187:auth2:(add_signed_ticket) Adding new ticket: <Ticket id=u'0b6225b6-be28-4579-9212-5a7c6c8830b9', url=u'https://lynx09.lab.eng.tlv2.redhat.com:54322' timeout=35998.66734004021 at 0x7fa6c3cb2c10>
>(Thread-9  ) INFO 2018-08-08 10:43:38,333 web:77:web:(close) FINISH [10.46.16.250] PUT /tickets/: [200] 0 [request=0.002795]
>(Thread-10 ) INFO 2018-08-08 10:43:38,709 web:97:web:(__call__) START: [10.46.16.250] DELETE /tickets/0e2b345c-3a83-4c27-891d-913d9ae38368
>(Thread-10 ) INFO 2018-08-08 10:43:38,709 auth:201:auth2:(delete_ticket) Deleting ticket u'0e2b345c-3a83-4c27-891d-913d9ae38368'
>(Thread-10 ) INFO 2018-08-08 10:43:38,710 web:77:web:(close) FINISH [10.46.16.250] DELETE /tickets/0e2b345c-3a83-4c27-891d-913d9ae38368: [204] 0 [request=0.001071]
>(Thread-11 ) INFO 2018-08-08 10:43:40,182 web:97:web:(__call__) START: [10.46.16.250] DELETE /tickets/c993ad83-9ed2-4de0-a87d-05b4e69f63b3
>(Thread-11 ) INFO 2018-08-08 10:43:40,183 auth:201:auth2:(delete_ticket) Deleting ticket u'c993ad83-9ed2-4de0-a87d-05b4e69f63b3'
>(Thread-11 ) INFO 2018-08-08 10:43:40,183 web:77:web:(close) FINISH [10.46.16.250] DELETE /tickets/c993ad83-9ed2-4de0-a87d-05b4e69f63b3: [204] 0 [request=0.001060]
>(Thread-12 ) INFO 2018-08-08 10:43:40,617 web:97:web:(__call__) START: [10.46.16.250] DELETE /tickets/830d5e73-10ab-4886-be06-e0888d41c1cc
>(Thread-12 ) INFO 2018-08-08 10:43:40,617 auth:201:auth2:(delete_ticket) Deleting ticket u'830d5e73-10ab-4886-be06-e0888d41c1cc'
>(Thread-12 ) INFO 2018-08-08 10:43:40,618 web:77:web:(close) FINISH [10.46.16.250] DELETE /tickets/830d5e73-10ab-4886-be06-e0888d41c1cc: [204] 0 [request=0.001108]
>(Thread-13 ) INFO 2018-08-08 10:43:41,142 web:97:web:(__call__) START: [10.46.16.250] DELETE /tickets/0b6225b6-be28-4579-9212-5a7c6c8830b9
>(Thread-13 ) INFO 2018-08-08 10:43:41,143 auth:201:auth2:(delete_ticket) Deleting ticket u'0b6225b6-be28-4579-9212-5a7c6c8830b9'
>(Thread-13 ) INFO 2018-08-08 10:43:41,143 web:77:web:(close) FINISH [10.46.16.250] DELETE /tickets/0b6225b6-be28-4579-9212-5a7c6c8830b9: [204] 0 [request=0.001059]
>(Thread-14 ) INFO 2018-08-08 10:47:58,675 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-14 ) INFO 2018-08-08 10:47:58,677 auth:187:auth2:(add_signed_ticket) Adding new ticket: <Ticket id=u'9e2a3955-9c79-4897-99b6-e9ce75959106', url=u'https://lynx09.lab.eng.tlv2.redhat.com:54322' timeout=35998.322129011154 at 0x7fa6c3cb2f10>
>(Thread-14 ) INFO 2018-08-08 10:47:58,678 web:77:web:(close) FINISH [10.46.16.250] PUT /tickets/: [200] 0 [request=0.002813]
>(Thread-15 ) INFO 2018-08-08 10:47:59,064 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-15 ) INFO 2018-08-08 10:47:59,066 auth:187:auth2:(add_signed_ticket) Adding new ticket: <Ticket id=u'93dbda9a-93e4-4ad9-baf4-3b2068f91989', url=u'https://lynx10.lab.eng.tlv2.redhat.com:54322' timeout=35998.93327498436 at 0x7fa6c3cb2d50>
>(Thread-15 ) INFO 2018-08-08 10:47:59,067 web:77:web:(close) FINISH [10.46.16.250] PUT /tickets/: [200] 0 [request=0.003404]
>(Thread-16 ) INFO 2018-08-08 10:47:59,173 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-16 ) INFO 2018-08-08 10:47:59,175 auth:187:auth2:(add_signed_ticket) Adding new ticket: <Ticket id=u'1810f202-faf7-453f-943e-a5c45acda74b', url=u'https://lynx10.lab.eng.tlv2.redhat.com:54322' timeout=35998.82456898689 at 0x7fa6c3cb2d90>
>(Thread-16 ) INFO 2018-08-08 10:47:59,176 web:77:web:(close) FINISH [10.46.16.250] PUT /tickets/: [200] 0 [request=0.002781]
>(Thread-17 ) INFO 2018-08-08 10:47:59,292 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-17 ) INFO 2018-08-08 10:47:59,294 auth:187:auth2:(add_signed_ticket) Adding new ticket: <Ticket id=u'9beb5ccc-b280-4f57-a077-0716ee9c3bab', url=u'https://lynx09.lab.eng.tlv2.redhat.com:54322' timeout=35998.70549893379 at 0x7fa6c3cb2dd0>
>(Thread-17 ) INFO 2018-08-08 10:47:59,295 web:77:web:(close) FINISH [10.46.16.250] PUT /tickets/: [200] 0 [request=0.002800]
>(Thread-18 ) INFO 2018-08-08 10:47:59,706 web:97:web:(__call__) START: [10.46.16.250] DELETE /tickets/93dbda9a-93e4-4ad9-baf4-3b2068f91989
>(Thread-18 ) INFO 2018-08-08 10:47:59,707 auth:201:auth2:(delete_ticket) Deleting ticket u'93dbda9a-93e4-4ad9-baf4-3b2068f91989'
>(Thread-18 ) INFO 2018-08-08 10:47:59,707 web:77:web:(close) FINISH [10.46.16.250] DELETE /tickets/93dbda9a-93e4-4ad9-baf4-3b2068f91989: [204] 0 [request=0.001168]
>(Thread-19 ) INFO 2018-08-08 10:48:01,336 web:97:web:(__call__) START: [10.46.16.250] DELETE /tickets/9e2a3955-9c79-4897-99b6-e9ce75959106
>(Thread-19 ) INFO 2018-08-08 10:48:01,336 auth:201:auth2:(delete_ticket) Deleting ticket u'9e2a3955-9c79-4897-99b6-e9ce75959106'
>(Thread-19 ) INFO 2018-08-08 10:48:01,337 web:77:web:(close) FINISH [10.46.16.250] DELETE /tickets/9e2a3955-9c79-4897-99b6-e9ce75959106: [204] 0 [request=0.001050]
>(Thread-20 ) INFO 2018-08-08 10:48:01,791 web:97:web:(__call__) START: [10.46.16.250] DELETE /tickets/1810f202-faf7-453f-943e-a5c45acda74b
>(Thread-20 ) INFO 2018-08-08 10:48:01,792 auth:201:auth2:(delete_ticket) Deleting ticket u'1810f202-faf7-453f-943e-a5c45acda74b'
>(Thread-20 ) INFO 2018-08-08 10:48:01,792 web:77:web:(close) FINISH [10.46.16.250] DELETE /tickets/1810f202-faf7-453f-943e-a5c45acda74b: [204] 0 [request=0.001087]
>(Thread-21 ) INFO 2018-08-08 10:48:02,369 web:97:web:(__call__) START: [10.46.16.250] DELETE /tickets/9beb5ccc-b280-4f57-a077-0716ee9c3bab
>(Thread-21 ) INFO 2018-08-08 10:48:02,369 auth:201:auth2:(delete_ticket) Deleting ticket u'9beb5ccc-b280-4f57-a077-0716ee9c3bab'
>(Thread-21 ) INFO 2018-08-08 10:48:02,369 web:77:web:(close) FINISH [10.46.16.250] DELETE /tickets/9beb5ccc-b280-4f57-a077-0716ee9c3bab: [204] 0 [request=0.001071]
>(Thread-22 ) INFO 2018-08-08 10:52:17,459 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-22 ) INFO 2018-08-08 10:52:17,466 auth:187:auth2:(add_signed_ticket) Adding new ticket: <Ticket id=u'51b8cd92-407b-45cc-bb2a-fc470ba0ba06', url=u'https://lynx10.lab.eng.tlv2.redhat.com:54322' timeout=35998.53340601921 at 0x7fa6c3cb2d50>
>(Thread-22 ) INFO 2018-08-08 10:52:17,467 web:77:web:(close) FINISH [10.46.16.250] PUT /tickets/: [200] 0 [request=0.007811]
>(Thread-23 ) INFO 2018-08-08 10:52:17,964 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-23 ) INFO 2018-08-08 10:52:17,966 auth:187:auth2:(add_signed_ticket) Adding new ticket: <Ticket id=u'cacd116b-3ecc-43a7-886c-704e14a6ce2f', url=u'https://lynx09.lab.eng.tlv2.redhat.com:54322' timeout=35999.033176898956 at 0x7fa6c3cb2f10>
>(Thread-23 ) INFO 2018-08-08 10:52:17,967 web:77:web:(close) FINISH [10.46.16.250] PUT /tickets/: [200] 0 [request=0.002806]
>(Thread-24 ) INFO 2018-08-08 10:52:18,003 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-24 ) INFO 2018-08-08 10:52:18,006 auth:187:auth2:(add_signed_ticket) Adding new ticket: <Ticket id=u'6f1d76f5-9524-4d03-94bc-b2a8b8dd18ba', url=u'https://lynx09.lab.eng.tlv2.redhat.com:54322' timeout=35998.99352192879 at 0x7fa6c3cb2f50>
>(Thread-24 ) INFO 2018-08-08 10:52:18,007 web:77:web:(close) FINISH [10.46.16.250] PUT /tickets/: [200] 0 [request=0.003582]
>(Thread-25 ) INFO 2018-08-08 10:52:18,065 web:97:web:(__call__) START: [10.46.16.250] PUT /tickets/
>(Thread-25 ) INFO 2018-08-08 10:52:18,068 auth:187:auth2:(add_signed_ticket) Adding new ticket: <Ticket id=u'4b5657fc-27ca-4541-9433-077f51c09acb', url=u'https://lynx10.lab.eng.tlv2.redhat.com:54322' timeout=35998.93177008629 at 0x7fa6c3cb2e10>
>(Thread-25 ) INFO 2018-08-08 10:52:18,068 web:77:web:(close) FINISH [10.46.16.250] PUT /tickets/: [200] 0 [request=0.003539]
>(Thread-26 ) INFO 2018-08-08 10:52:19,410 web:97:web:(__call__) START: [10.46.16.250] DELETE /tickets/cacd116b-3ecc-43a7-886c-704e14a6ce2f
>(Thread-26 ) INFO 2018-08-08 10:52:19,410 auth:201:auth2:(delete_ticket) Deleting ticket u'cacd116b-3ecc-43a7-886c-704e14a6ce2f'
>(Thread-26 ) INFO 2018-08-08 10:52:19,411 web:77:web:(close) FINISH [10.46.16.250] DELETE /tickets/cacd116b-3ecc-43a7-886c-704e14a6ce2f: [204] 0 [request=0.001056]
>(Thread-27 ) INFO 2018-08-08 10:52:19,854 web:97:web:(__call__) START: [10.46.16.250] DELETE /tickets/51b8cd92-407b-45cc-bb2a-fc470ba0ba06
>(Thread-27 ) INFO 2018-08-08 10:52:19,854 auth:201:auth2:(delete_ticket) Deleting ticket u'51b8cd92-407b-45cc-bb2a-fc470ba0ba06'
>(Thread-27 ) INFO 2018-08-08 10:52:19,855 web:77:web:(close) FINISH [10.46.16.250] DELETE /tickets/51b8cd92-407b-45cc-bb2a-fc470ba0ba06: [204] 0 [request=0.001100]
>(Thread-28 ) INFO 2018-08-08 10:52:20,383 web:97:web:(__call__) START: [10.46.16.250] DELETE /tickets/6f1d76f5-9524-4d03-94bc-b2a8b8dd18ba
>(Thread-28 ) INFO 2018-08-08 10:52:20,383 auth:201:auth2:(delete_ticket) Deleting ticket u'6f1d76f5-9524-4d03-94bc-b2a8b8dd18ba'
>(Thread-28 ) INFO 2018-08-08 10:52:20,384 web:77:web:(close) FINISH [10.46.16.250] DELETE /tickets/6f1d76f5-9524-4d03-94bc-b2a8b8dd18ba: [204] 0 [request=0.001060]
>(Thread-29 ) INFO 2018-08-08 10:52:20,826 web:97:web:(__call__) START: [10.46.16.250] DELETE /tickets/4b5657fc-27ca-4541-9433-077f51c09acb
>(Thread-29 ) INFO 2018-08-08 10:52:20,826 auth:201:auth2:(delete_ticket) Deleting ticket u'4b5657fc-27ca-4541-9433-077f51c09acb'
>(Thread-29 ) INFO 2018-08-08 10:52:20,827 web:77:web:(close) FINISH [10.46.16.250] DELETE /tickets/4b5657fc-27ca-4541-9433-077f51c09acb: [204] 0 [request=0.001055]

Actions: View

Attachments on bug 1576500: 1433933 | 1435578 | 1474615 | 1474617 | 1477188 | 1514056