2 Replies Latest reply on Oct 6, 2016 10:02 AM by Toby Erkson

    VizAlert fails on the hour but works the rest of the time.  Timeout rule being triggered?

    Toby Erkson

      VizAlerts 1.1, runs every minute

      Production Tableau Server version 10.0.1

      Full sample error log entry:

      2016-10-06 07:00:06 - [INFO] - LoggerQuickSetup - Logging initialized, writing to .\logs\vizalerts.log_2016-10-06.log
      2016-10-06 07:00:06 - [DEBUG] - get_password_from_file - Opening password file D:\Application\Tableau\VizAlerts\config\password.txt for reading
      2016-10-06 07:00:06 - [DEBUG] - trusted_ticket_test - testing trusted ticket: myServer.com, americas.corpdir.net\terkson, None
      2016-10-06 07:00:06 - [DEBUG] - get_trusted_ticket - Generating trusted ticket. Request details: Server: myServer.com, Site: , Username: americas.corpdir.net\terkson, Url: http://myServer.com/trusted, Postdata: username=americas.corpdir.net%5Cterkson.
      2016-10-06 07:00:06 - [DEBUG] - get_trusted_ticket - Got ticket: 0gFjTdB18Id-C5w3oZpZisdy
      2016-10-06 07:00:06 - [DEBUG] - trusted_ticket_test - Generated test trusted ticket. Value is: 0gFjTdB18Id-C5w3oZpZisdy
      2016-10-06 07:00:06 - [DEBUG] - get_views - PostgreSQL repository returned 4 rows
      2016-10-06 07:00:06 - [DEBUG] - get_views - Checking rule with from: 0, to: 3600, timeout: 75
      2016-10-06 07:00:06 - [DEBUG] - get_views - Checking rule with from: 3601, to: 7200, timeout: 90
      2016-10-06 07:00:06 - [DEBUG] - get_views - Checking rule with from: 7201, to: 14400, timeout: 120
      2016-10-06 07:00:06 - [DEBUG] - get_views - Checking rule with from: 14401, to: 315360000, timeout: 300
      2016-10-06 07:00:06 - [DEBUG] - get_views - using timeout 60s, data retrieval tries 1, due to it being 3600.761 seconds since last run.
      2016-10-06 07:00:06 - [INFO] - main - Processing a total of 1 views
      2016-10-06 07:00:06 - [DEBUG] - process_views - Processing subscription_id 281, view_id 20404, site_name area51, customized view id None, view_name AlertList_Report
      2016-10-06 07:00:06 - [DEBUG] - address_is_invalid - Splitting Address: localpart, domainname, host, toplevel: toby.erkson,myServer.com,myServer,com
      2016-10-06 07:00:06 - [DEBUG] - address_is_invalid - Removing other characters from address: localpart, host: tobyerkson,myServer
      2016-10-06 07:00:06 - [DEBUG] - get_trusted_ticket - Generating trusted ticket. Request details: Server: myServer.com, Site: area51, Username: terkson, Url: http://myServer.com/trusted, Postdata: username=terkson&target_site=area51.
      2016-10-06 07:00:06 - [DEBUG] - get_trusted_ticket - Got ticket: GtE7reuzEVB7VxK3b5KayRXT
      2016-10-06 07:00:06 - [DEBUG] - export_view - Getting vizdata from: http://myServer.com/trusted/GtE7reuzEVB7VxK3b5KayRXT/t/area51/views/VizAlerts_AlertsAlerter/AlertList_Report?&:format=csv&:refresh=y
      2016-10-06 07:00:06 - [INFO] - _new_conn - Starting new HTTP connection (1): myServer.com
      2016-10-06 07:00:06 - [DEBUG] - _make_request - "GET /trusted/GtE7reuzEVB7VxK3b5KayRXT/t/area51/views/VizAlerts_AlertsAlerter/AlertList_Report?&:format=csv&:refresh=y HTTP/1.1" 302 0
      2016-10-06 07:00:07 - [DEBUG] - _make_request - "GET /t/area51/views/VizAlerts_AlertsAlerter/AlertList_Report?&:format=csv&:refresh=y HTTP/1.1" 406 0
      2016-10-06 07:00:07 - [ERROR] - export_view - Unable to get vizdata from url http://myServer.com/t/area51/views/VizAlerts_AlertsAlerter/AlertList_Report?&:format=csv&:refresh=y. Cause: 
      2016-10-06 07:00:07 - [ERROR] - process_views - Unable to export viewname AlertList_Report as csv, error: Unable to get vizdata from url http://myServer.comt/area51/views/VizAlerts_AlertsAlerter/AlertList_Report?&:format=csv&:refresh=y. Cause: 
      2016-10-06 07:00:07 - [INFO] - send_email - sending email: mail.myServer.com,ec_164_tableau-support@myServer.com,toby.erkson@myServer.com,toby.erkson@myServer.com,None,VizAlerts was unable to process view AlertList_Report,None
      2016-10-06 07:00:07 - [DEBUG] - send_email - email body: VizAlerts was unable to export data for this view. Error message: Unable to export viewname AlertList_Report as csv, error: Unable to get vizdata from url http://myServer.com/t/area51/views/VizAlerts_AlertsAlerter/AlertList_Report?&:format=csv&:refresh=y. Cause: <br><br><b>Details:</b><br><br><b>View URL:</b> <a href="http://myServer.com/t/area51/views/VizAlerts_AlertsAlerter/AlertList_Report">http://myServer.com/t/area51/views/VizAlerts_AlertsAlerter/AlertList_Report<a><br><b>Subscriber:</b> <a href="mailto:toby.erkson@myServer.com">terkson</a><br><b>View Owner:</b> <a href="mailto:toby.erkson@myServer.com">terkson</a><br><b>Site Id:</b> area51<br><b>Project:</b> Default
      

       

      Another one with just the rule checking:

      2016-10-06 03:01:06 - [DEBUG] - trusted_ticket_test - Generated test trusted ticket. Value is: fZoh5Nz2QJznLD6dZWIVpc9y
      2016-10-06 03:01:06 - [DEBUG] - get_views - PostgreSQL repository returned 4 rows
      2016-10-06 03:01:06 - [DEBUG] - get_views - Checking rule with from: 0, to: 3600, timeout: 75
      2016-10-06 03:01:06 - [DEBUG] - get_views - Rule applies!
      2016-10-06 03:01:06 - [DEBUG] - get_views - using timeout 75s, data retrieval tries 1, due to it being 3599.778 seconds since last run.
      2016-10-06 03:01:06 - [INFO] - main - Processing a total of 1 views
      

       

      The VizAlert that runs every hour and the one that only runs at 6AM weekdays each have a default priority of 5.  That priority trumps all other schedules, I made sure of that!  All VizAlert and extract schedules are Parallel if that matters.

       

      There are a minimum of 32 full extracts at the top of each hour along with 9 subscriptions.  There are other schedules that run on the hour that can add to the load e.g. Weekdays - 6AM Pacific, Daily 15 Minute Update - 5am-11pm, etc.

      What is interesting is that these 'on the hour' failures happened after a successful upgrade to version 10.0.1   With version 9.3.4 I rarely ever had this issue.

       

      Should I increase the retries? Or extend the timeouts?  Suggestions?

       

        • 1. Re: VizAlert fails on the hour but works the rest of the time.  Timeout rule being triggered?
          Matt Coles

          Key line:

           

          2016-10-06 07:00:07 - [DEBUG] - _make_request - "GET /t/area51/views/VizAlerts_AlertsAlerter/AlertList_Report?&:format=csv&:refresh=y HTTP/1.1" 406

           

          The HTTP 406 code "Not Acceptable", I have found, is what Tableau Server returns when it can't give you what you want (imho, a 500 is maybe a better code). It can mean that the viz failed to render due to a connection issue, a crash, or pretty much any other reason, including incorrect permissions (why isn't that a 401??). So when I see a 406 happen, I manually load the url it was trying to hit with my browser, and see if I can load it. Usually, the error becomes apparent that way. It may be the case that your postgresql db isn't returning the query quickly enough while it's trying to do a ton of updates, brought on by the other work the cluster is doing on the top of the hour. The viz load itself isn't timing out, though-if it was, you'd see "read timeout" in the error log and email.

          1 of 1 people found this helpful
          • 2. Re: VizAlert fails on the hour but works the rest of the time.  Timeout rule being triggered?
            Toby Erkson

            Thanks Matt.  For some reason the embedded credentials changed to prompt and thus there was no subscription option on the report page and, of course, w/o credentials it was failing.

            I re-published w/embedded credentials and that fixed the issue.  This isn't the first time a server upgrade randomly broke embedded credentialing