"job closed" entries not logged in TIBCO Spotfire Server sql.log after executing any Information Link
Article ID: KB0075395
Updated On:
| Products | Versions |
|---|---|
| Spotfire Server | All Versions |
Description
After successful execution of an Information Link, the ‘job closed’ entries in TIBCO Spotfire Server sql.log provide information about the total time the query took from query execution until the client has received all the result data. This information helps when troubleshooting performance issues with the information links. For more information on this, refer section "Identify Information Link execution in sql.log” in KB Troubleshooting Guide: Performance issues with Information Links.
However in the sql.log (<Spotfire server installation>\tomcat\logs) you may see those "job closed" entries are not getting logged at all.
For example, in these log entries, the "job closed" entry does not get logged after executing information link 'USERS':
2020-04-02T07:03:57,626+0530 [*pool-12-thread-1, boston\demo_user, #3, #6599*]: Executing Information Link 'USERS' (01ea968e-2de6-458c-9bae-00f2b388db6e):
Columns:
USER_ID (eade3988-fe22-454c-93be-9bc65b6dbe7b)
USER_NAME (fee6f972-87bb-4a06-b390-6a3b173caec3)
DOMAIN_NAME (019b9ced-fe1a-4a8b-8c63-9dfffd5bf2d5)
EXTERNAL_ID (76aaf0b3-9273-4671-81d3-5eb15c5bf2c8)
PRIMARY_GROUP_ID (39141a36-62b5-4910-8408-5f53e9a6f31f)
LAST_MODIFIED_MEMBERSHIP (b3d5dc74-8714-462f-b106-40a4b4dec780)
PASSWORD (10f41856-7335-4898-8138-663574b63efe)
DISPLAY_NAME (94308824-30aa-474f-830d-2e7e279625dd)
EMAIL (b18c3290-9982-4843-bb02-0f0e86718b44)
ENABLED (9cdbd3f4-6394-483c-a8f1-851192346ff3)
LOCKED_UNTIL (fef6e6a3-2807-4cf9-92cf-9260e2330ce3)
LAST_LOGIN (53bbc983-f788-436c-941d-2c312bbb1aea)
2020-04-02T07:03:57,642+0530 [*pool-12-thread-1, boston\demo_user, #3, #6599*]: [data-source="Test_DataSource"]
SELECT
U1."USER_ID" AS "USERID",
U1."USER_NAME" AS "USERNAME",
U1."DOMAIN_NAME" AS "DOMAINNAME",
U1."EXTERNAL_ID" AS "EXTERNALID",
U1."PRIMARY_GROUP_ID" AS "PRIMARYGROUPID",
U1."LAST_MODIFIED_MEMBERSHIP" AS "LASTMODIFIEDMEMBERSHIP",
U1."PASSWORD" AS "PASSWORD",
U1."DISPLAY_NAME" AS "DISPLAYNAME",
U1."EMAIL" AS "EMAIL",
U1."ENABLED" AS "ENABLED",
U1."LOCKED_UNTIL" AS "LOCKEDUNTIL",
U1."LAST_LOGIN" AS "LASTLOGIN"
FROM
"spotfire_server_1033"."dbo"."USERS" U1
2020-04-02T07:03:57,922+0530 [*pool-12-thread-2, boston\demo_user, #3, #6599*]: Information Link 'USERS' (01ea968e-2de6-458c-9bae-00f2b388db6e) executed successfully, time: 0.296 seconds
However in the sql.log (<Spotfire server installation>\tomcat\logs) you may see those "job closed" entries are not getting logged at all.
For example, in these log entries, the "job closed" entry does not get logged after executing information link 'USERS':
2020-04-02T07:03:57,626+0530 [*pool-12-thread-1, boston\demo_user, #3, #6599*]: Executing Information Link 'USERS' (01ea968e-2de6-458c-9bae-00f2b388db6e):
Columns:
USER_ID (eade3988-fe22-454c-93be-9bc65b6dbe7b)
USER_NAME (fee6f972-87bb-4a06-b390-6a3b173caec3)
DOMAIN_NAME (019b9ced-fe1a-4a8b-8c63-9dfffd5bf2d5)
EXTERNAL_ID (76aaf0b3-9273-4671-81d3-5eb15c5bf2c8)
PRIMARY_GROUP_ID (39141a36-62b5-4910-8408-5f53e9a6f31f)
LAST_MODIFIED_MEMBERSHIP (b3d5dc74-8714-462f-b106-40a4b4dec780)
PASSWORD (10f41856-7335-4898-8138-663574b63efe)
DISPLAY_NAME (94308824-30aa-474f-830d-2e7e279625dd)
EMAIL (b18c3290-9982-4843-bb02-0f0e86718b44)
ENABLED (9cdbd3f4-6394-483c-a8f1-851192346ff3)
LOCKED_UNTIL (fef6e6a3-2807-4cf9-92cf-9260e2330ce3)
LAST_LOGIN (53bbc983-f788-436c-941d-2c312bbb1aea)
2020-04-02T07:03:57,642+0530 [*pool-12-thread-1, boston\demo_user, #3, #6599*]: [data-source="Test_DataSource"]
SELECT
U1."USER_ID" AS "USERID",
U1."USER_NAME" AS "USERNAME",
U1."DOMAIN_NAME" AS "DOMAINNAME",
U1."EXTERNAL_ID" AS "EXTERNALID",
U1."PRIMARY_GROUP_ID" AS "PRIMARYGROUPID",
U1."LAST_MODIFIED_MEMBERSHIP" AS "LASTMODIFIEDMEMBERSHIP",
U1."PASSWORD" AS "PASSWORD",
U1."DISPLAY_NAME" AS "DISPLAYNAME",
U1."EMAIL" AS "EMAIL",
U1."ENABLED" AS "ENABLED",
U1."LOCKED_UNTIL" AS "LOCKEDUNTIL",
U1."LAST_LOGIN" AS "LASTLOGIN"
FROM
"spotfire_server_1033"."dbo"."USERS" U1
2020-04-02T07:03:57,922+0530 [*pool-12-thread-2, boston\demo_user, #3, #6599*]: Information Link 'USERS' (01ea968e-2de6-458c-9bae-00f2b388db6e) executed successfully, time: 0.296 seconds
Issue/Introduction
This article explains why the "job closed" entries are not logged in the TIBCO Spotfire Server sql.log after executing any Information Link.
Resolution
The “job closed” entries in sql.log are getting captured only when TIBCO Spotfire Server logs are captured in DEBUG mode. To resolve, enable DEBUG logging on the TIBCO Spotfire Server per Changing server and node logging levels. The note is mentioned on Server and node logging levels reference.
Here are some example logs with Spotfire Server DEBUG logging enabled where "job closed" entry gets logged after executing same information link 'USERS':
2020-04-02T07:07:40,854+0530 [*pool-12-thread-3, boston\demo_user, #3, #6650*]: Executing Information Link 'USERS' (01ea968e-2de6-458c-9bae-00f2b388db6e):
Columns:
USER_ID (eade3988-fe22-454c-93be-9bc65b6dbe7b)
USER_NAME (fee6f972-87bb-4a06-b390-6a3b173caec3)
DOMAIN_NAME (019b9ced-fe1a-4a8b-8c63-9dfffd5bf2d5)
EXTERNAL_ID (76aaf0b3-9273-4671-81d3-5eb15c5bf2c8)
PRIMARY_GROUP_ID (39141a36-62b5-4910-8408-5f53e9a6f31f)
LAST_MODIFIED_MEMBERSHIP (b3d5dc74-8714-462f-b106-40a4b4dec780)
PASSWORD (10f41856-7335-4898-8138-663574b63efe)
DISPLAY_NAME (94308824-30aa-474f-830d-2e7e279625dd)
EMAIL (b18c3290-9982-4843-bb02-0f0e86718b44)
ENABLED (9cdbd3f4-6394-483c-a8f1-851192346ff3)
LOCKED_UNTIL (fef6e6a3-2807-4cf9-92cf-9260e2330ce3)
LAST_LOGIN (53bbc983-f788-436c-941d-2c312bbb1aea)
2020-04-02T07:07:40,854+0530 [*pool-12-thread-3, boston\demo_user, #3, #6650*]: [data-source="Test_DataSource"]
SELECT
U1."USER_ID" AS "USERID",
U1."USER_NAME" AS "USERNAME",
U1."DOMAIN_NAME" AS "DOMAINNAME",
U1."EXTERNAL_ID" AS "EXTERNALID",
U1."PRIMARY_GROUP_ID" AS "PRIMARYGROUPID",
U1."LAST_MODIFIED_MEMBERSHIP" AS "LASTMODIFIEDMEMBERSHIP",
U1."PASSWORD" AS "PASSWORD",
U1."DISPLAY_NAME" AS "DISPLAYNAME",
U1."EMAIL" AS "EMAIL",
U1."ENABLED" AS "ENABLED",
U1."LOCKED_UNTIL" AS "LOCKEDUNTIL",
U1."LAST_LOGIN" AS "LASTLOGIN"
FROM
"spotfire_server_1033"."dbo"."USERS" U1
2020-04-02T07:07:40,870+0530 [*pool-12-thread-4, boston\demo_user, #3, #6650*]: Information Link 'USERS' (01ea968e-2de6-458c-9bae-00f2b388db6e) executed successfully, time: 0.016 seconds
2020-04-02T07:07:40,932+0530 [*Thread-27, boston\demo_user, #3, #6650*]: Information Link 'USERS' (01ea968e-2de6-458c-9bae-00f2b388db6e) job closed, time: 0.078 seconds
Here are some example logs with Spotfire Server DEBUG logging enabled where "job closed" entry gets logged after executing same information link 'USERS':
2020-04-02T07:07:40,854+0530 [*pool-12-thread-3, boston\demo_user, #3, #6650*]: Executing Information Link 'USERS' (01ea968e-2de6-458c-9bae-00f2b388db6e):
Columns:
USER_ID (eade3988-fe22-454c-93be-9bc65b6dbe7b)
USER_NAME (fee6f972-87bb-4a06-b390-6a3b173caec3)
DOMAIN_NAME (019b9ced-fe1a-4a8b-8c63-9dfffd5bf2d5)
EXTERNAL_ID (76aaf0b3-9273-4671-81d3-5eb15c5bf2c8)
PRIMARY_GROUP_ID (39141a36-62b5-4910-8408-5f53e9a6f31f)
LAST_MODIFIED_MEMBERSHIP (b3d5dc74-8714-462f-b106-40a4b4dec780)
PASSWORD (10f41856-7335-4898-8138-663574b63efe)
DISPLAY_NAME (94308824-30aa-474f-830d-2e7e279625dd)
EMAIL (b18c3290-9982-4843-bb02-0f0e86718b44)
ENABLED (9cdbd3f4-6394-483c-a8f1-851192346ff3)
LOCKED_UNTIL (fef6e6a3-2807-4cf9-92cf-9260e2330ce3)
LAST_LOGIN (53bbc983-f788-436c-941d-2c312bbb1aea)
2020-04-02T07:07:40,854+0530 [*pool-12-thread-3, boston\demo_user, #3, #6650*]: [data-source="Test_DataSource"]
SELECT
U1."USER_ID" AS "USERID",
U1."USER_NAME" AS "USERNAME",
U1."DOMAIN_NAME" AS "DOMAINNAME",
U1."EXTERNAL_ID" AS "EXTERNALID",
U1."PRIMARY_GROUP_ID" AS "PRIMARYGROUPID",
U1."LAST_MODIFIED_MEMBERSHIP" AS "LASTMODIFIEDMEMBERSHIP",
U1."PASSWORD" AS "PASSWORD",
U1."DISPLAY_NAME" AS "DISPLAYNAME",
U1."EMAIL" AS "EMAIL",
U1."ENABLED" AS "ENABLED",
U1."LOCKED_UNTIL" AS "LOCKEDUNTIL",
U1."LAST_LOGIN" AS "LASTLOGIN"
FROM
"spotfire_server_1033"."dbo"."USERS" U1
2020-04-02T07:07:40,870+0530 [*pool-12-thread-4, boston\demo_user, #3, #6650*]: Information Link 'USERS' (01ea968e-2de6-458c-9bae-00f2b388db6e) executed successfully, time: 0.016 seconds
2020-04-02T07:07:40,932+0530 [*Thread-27, boston\demo_user, #3, #6650*]: Information Link 'USERS' (01ea968e-2de6-458c-9bae-00f2b388db6e) job closed, time: 0.078 seconds
Additional Information
Doc: Changing server and node logging levels
Doc : Server logging levels
KB: Troubleshooting Guide: Performance issues with Information Links
Feedback
Yes
No
Powered by
