0

I have a stored procedure that works fine when run using EXEC, but fails when added as a step to an Agent job. The stored procedure requires no parameters. It is used to process a bunch of geographic shapes in a vendor database and cache the resulting MS geography objects for use by other processes.

Stored procedure:

SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO

ALTER PROCEDURE [dbo].[sp_job_update_shapes_ex]
AS
BEGIN
    SET NOCOUNT ON

    --debug 
    DECLARE @ProcessName varchar(50) = ISNULL(OBJECT_NAME(@@PROCID), 'update_shape_ex')
    DECLARE @Message varchar(1000)
    DECLARE @SessionName varchar(50) = 'ugp_' + CONVERT(VARCHAR(20), GETDATE(), 120)

    DECLARE @LogSevereError int = 1
    DECLARE @LogError int = 2
    DECLARE @LogInfo int = 3
    DECLARE @LogVerbose int = 4
    DECLARE @LogDebug int = 5

    DECLARE @ShapeId int
    DECLARE @Polygon geography
    DECLARE @RC int
    DECLARE @NodeTypeId int
    DECLARE @NodeTypeGz int = 5
    DECLARE @NodeTypePoi int = 15
    DECLARE @ShapeName varchar(10)
    DECLARE @ShapeNameGz varchar(10) = 'Geozone'
    DECLARE @ShapeNamePoi varchar(10) = 'POI'

    SET @Message = 'Begin ' + @ProcessName 
    EXEC sp_Log @ProcessName, @Message, @SessionName, @LogInfo

    /****************************************************************************/
    SET @Message = 'Insert new Geozones into GeozoneEx'
    EXEC sp_Log @ProcessName, @Message, @SessionName, @LogInfo

    INSERT INTO GeozoneEx (GeozoneId, GeozoneUsageId)
    SELECT GeozoneId = NodeId,
        GeozoneUsageId = 0
    FROM Ctrack6..Nodes n
    WHERE n.NodeTypeId = @NodeTypeGz
    and n.NodeIsActive = 1
    and n.NodeId NOT IN (SELECT GeozoneId FROM GeozoneEx)

    SET @Message = 'Rows Inserted: ' + CONVERT(VARCHAR(5), @@ROWCOUNT)
    EXEC sp_Log @ProcessName, @Message, @SessionName, @LogInfo


    /****************************************************************************/
    SET @Message = 'Insert new POI into PoiEx'
    EXEC sp_Log @ProcessName, @Message, @SessionName, @LogInfo

    INSERT INTO PoiEx (PoiId)
    SELECT NodeId
    FROM Ctrack6..Nodes n
    WHERE n.NodeTypeId = @NodeTypePoi
    and n.NodeIsActive = 1
    and n.NodeId NOT IN (SELECT PoiId FROM PoiEx)

    SET @Message = 'Rows Inserted: ' + CONVERT(VARCHAR(5), @@ROWCOUNT)
    EXEC sp_Log @ProcessName, @Message, @SessionName, @LogInfo


    /****************************************************************************/
    SET @Message = 'Greate Polygons for shapes with NodeType (' + @ShapeNameGz + ', ' + @ShapeNamePoi + ')'
    EXEC sp_Log @ProcessName, @Message, @SessionName, @LogInfo

    DECLARE _shape CURSOR FOR
    SELECT NodeId, NodeTypeId
    FROM Ctrack6..Nodes
    WHERE NodeTypeId IN (@NodeTypeGz, @NodeTypePoi)
    AND NodeIsActive = 1
    --SELECT NodeId
    --FROM vwGeozones
    --WHERE GzPolygon IS NULL

    OPEN _shape
        FETCH NEXT FROM _shape INTO @ShapeId, @NodeTypeId
        WHILE @@FETCH_STATUS = 0
        BEGIN
            SET @RC = 0
            SET @Polygon = NULL

            IF @NodeTypeId = @NodeTypeGz
            BEGIN
                SET @ShapeName = @ShapeNameGz
            END
            ELSE IF @NodeTypeId = @NodeTypePoi
            BEGIN
                SET @ShapeName = @ShapeNamePoi
            END
            ELSE
            BEGIN
                SET @ShapeName = 'Unknown'
            END

            SET @Message = 'Creating polygon for shape ' + @ShapeName + ': ' + CONVERT(VARCHAR(10), @ShapeId)
            EXEC sp_Log @ProcessName, @Message, @SessionName, @LogInfo

            EXEC @RC = sp_convert_shape_to_geography @SessionName, @ShapeId, @Polygon OUTPUT

            IF @RC = 0
            BEGIN
                IF @NodeTypeId = @NodeTypeGz
                BEGIN
                    UPDATE GeozoneEx
                    SET Polygon = @Polygon
                    WHERE GeozoneId = @ShapeId
                END
                ELSE IF @NodeTypeId = @NodeTypePoi
                BEGIN
                    UPDATE PoiEx
                    SET Polygon = @Polygon
                    WHERE PoiId = @ShapeId
                END
                ELSE
                BEGIN
                    SET @Message = 'Successfully created polygon, but cannot save as shape is ' + @Shapename + ': ' + CONVERT(VARCHAR(10), @ShapeId)
                    EXEC sp_Log @ProcessName, @Message, @SessionName, @LogError
                END
            END
            ELSE
            BEGIN
                SET @Message = 'Error creating polygon for shape ' + @Shapename + ': ' + CONVERT(VARCHAR(10), @ShapeId)
                EXEC sp_Log @ProcessName, @Message, @SessionName, @LogError
            END

            FETCH NEXT FROM _shape INTO @ShapeId, @NodeTypeId
        END
    CLOSE _shape
    DEALLOCATE _shape

    SET @Message = 'End ' + @ProcessName 
    EXEC sp_Log @ProcessName, @Message, @SessionName, @LogInfo

END

SQL Server agent job:

When the stored procedure is created as a step in a job, it fails with no real log info available.

Stored procedure created as job:

Stored procedure created as job

Job failed message:

Job failed message

Job History Log:

Job History Log

History lLog:

Date        2/08/2018 12:59:08 PM
Log     Job History (Cache Geozones and POI)

Step ID     1
Server      KINGSFELD
Job Name        Cache Geozones and POI
Step Name       exec sp_job_update_shapes_ex
Duration        00:00:01
Sql Severity    16
Sql Message ID  6522
Operator Emailed    
Operator Net sent   
Operator Paged  
Retries Attempted   0

Message
Executed as user: NT AUTHORITY\SYSTEM. ..._shapes_ex    Begin sp_job_update_shapes_ex 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_job_update_shapes_ex Insert new Geozones into GeozoneEx 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_job_update_shapes_ex Rows Inserted: 0 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_job_update_shapes_ex Insert new POI into PoiEx 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_job_update_shapes_ex Rows Inserted: 0 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_job_update_shapes_ex Greate Polygons for shapes with NodeType (Geozone, POI) 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_job_update_shapes_ex Creating polygon for shape POI: 500 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Process:    Begin sp_convert_shape_to_geography 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Vars:   Declare Variables 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Vars:   Declare @Coords Temp Table 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Data:   Get Shape NodeType 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Data:   NodeType: POI 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Data:   POI: 500:Kingsfeld Pleasure Pt Depot 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Data:   Shape: -1:Point 
[SQLSTATE 01000] (Message 50000)  5 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Point:  Lat/Lng: -33.967829, 150.979922 
[SQLSTATE 01000] (Message 50000)  4 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Results:    Polygon Details: POLYGON ((150.98460895783668 -33.970080208112478, 150.98496365755059 -33.966194313013752, 150.98153028383197 -33.963525070916354, 150.97687086935508 -33.964106438622437, 150.97452729769748 -33.967487342906665, 150.97622732051045 -33.971121920298295, 150.98072449201612 -33.972286713684234, 150.98460895783668 -33.970080208112478)) 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Process:    End sp_convert_shape_to_geography 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_job_update_shapes_ex Creating polygon for shape POI: 557 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Process:    Begin sp_convert_shape_to_geography 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Vars:   Declare Variables 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Vars:   Declare @Coords Temp Table 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Data:   Get Shape NodeType 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Data:   NodeType: POI 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Data:   POI: 557:Tandem Tipper Hire 
[SQLSTATE 01000] (Message 50000)  3 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Data:   Shape: -1:Point 
[SQLSTATE 01000] (Message 50000)  5 2018-08-02 12:59:08 ugp_2018-08-02 12:59:08 sp_convert_shape_to_geography   Point:  Lat/Lng: -33.935224, 150.940033 
[SQLSTATE 01000] (Message 50000)  4 2018-08-02 12:59:08 ugp_2018-08-02...  The step failed.

I've tried running a profile (SP template) but I'm obviously doing something wrong, as I can't see the stored procedure start, despite there being output from it. I'll try again after lunch.

Why is my stored procedure failing when run with the Job Agent? How can I find the cause?

marc_s
  • 732,580
  • 175
  • 1,330
  • 1,459
Hecatonchires
  • 1,009
  • 4
  • 13
  • 42
  • 2
    the history log doesn't say much about the error. Try executing it in the query window using the same user as the SQL Agent. `execute as login = 'login name'` – Squirrel Aug 02 '18 at 03:39
  • Side note: you should **not** use the `sp_` prefix for your stored procedures. Microsoft has [reserved that prefix for its own use (see *Naming Stored Procedures*)](http://msdn.microsoft.com/en-us/library/ms190669%28v=sql.105%29.aspx), and you do run the risk of a name clash sometime in the future. [It's also bad for your stored procedure performance](http://www.sqlperformance.com/2012/10/t-sql-queries/sp_prefix). It's best to just simply avoid `sp_` and use something else as a prefix - or no prefix at all! – marc_s Aug 02 '18 at 04:15
  • Interesting article @marc_s. looks like i have a refactoring project in my future :P – Hecatonchires Aug 02 '18 at 04:25

1 Answers1

0

TSQL job steps run under the credentials of the Job owner. Here it is executing as NT AUTHORITY\SYSTEM. Update the job owner as sa or another user with right credentials.

Or, If possible or run the stored procedure under a specific credential as 

CREATE PROCEDURE <procedure name>
EXECUTE AS OWNER 

or

CREATE PROCEDURE <procedure name>
EXECUTE AS 'specificUser'

Read more on Execute AS

Venkataraman R
  • 12,181
  • 2
  • 31
  • 58
  • The job is owned by sa :/ – Hecatonchires Aug 02 '18 at 04:31
  • I think your sql server sa is `NT AUTHORITY\SYSTEM`. Give sufficient permissions to this account or make another privileged account as 'sa` or change job owner to some other privileged user. – Venkataraman R Aug 02 '18 at 04:41
  • I tried using `EXECUTE AS 'sa'` and had insufficient permissions. Then `EXECUTE AS OWNER` which had the same issues, and then `EXECUTE AS CALLER` to remove owner. This is where it started working. Wierd. Accepting. – Hecatonchires Aug 03 '18 at 00:22