Hi, When I sent a report via defer run, and it keep as queue...

[john cullen]

I would server trace the error and open a case. Position 1 click away from the error, turn on server traces, reproduce the error in one click, turn off traces, run the savediag option with Post turned off. It will make a zip file you can upload to the case.

Then notice the TSCOM id that was used to create the error, and look for in the traces for that tscomid.

there are usually three files. the request, the output, and the trace file. Look at the tscomxxx.out first. it can have clues. else study the .trc file and see if you can figure out from there. this is what the case workers will do in NYC.

[Toby Mills]

Hi Nox

I agree with JNC - a savediag is probably in order.

One thing Ill mention - Scanning probably refers to the WFRS trying to scan the app folders. And youve got another question here about app folders being hard to read.

Coincidence

Statitics on the Scheduler service help shows this metric:

Last Full Scan

Timestamp for the last full scan of the application path. A full scan is performed on the Scheduler Start and Force Rescan options, which are available on the Scheduler menu.

I would not be surprised to see you solve both problems at once by opening a case.

Keep us posted on what it turns out to be. Do you need help making a savediag for support.tibco.com

[Nox Lee]

Hi,

When I sent a report via defer run, and it keep as queued and there is no other job is running. It wont go anywhere unless I use Force Rescan on Scheduler Service. when I check on edaprint.log and I keep see " W dfm scan failed, postponed for 1 second" and idea what went wrong

[Nox Lee]

Hi @toby.mills ,

unfortunately both of my recent question came from two different machine. I have open a case with IBI tech support already, but meanwhile that we can try update here as well for future references.

I have look through the savediags edaprint.log and all I see at end are:

 

08/05/2021 10:08:00.644 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:00.645 I connecting cmrpaq000002 tscomid=662,sesid=61532,fctkt=610a5801:1-f009,fcdir=aq0000020155

08/05/2021 10:08:00.662 I disconnect cmrpaq000002 tscomid=662,sesid=61532,fctkt=610a5801:1-f009,fcdir=aq0000020155

08/05/2021 10:08:00.662 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:00.664 I request by t3rp22025 to notify disconnect of sesid=61532

08/05/2021 10:08:00.665 I statistics cmrpaq000002 sesid=61532,cpu=0.010s,dbms=0.000s,srv=0.020s

08/05/2021 10:08:01.302 I accepting cmrpht000086 tcp=192.168.40.200:10139

08/05/2021 10:08:01.306 I request by cmrpht000086 to POST u=OPSYSwf_admin,session=610a5801:1-ebb9, page=WOPTIONSLINK

08/05/2021 10:08:01.666 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:01.668 I connecting cmrpaq000002 tscomid=662,sesid=61533,fctkt=610a5801:1-f00a,fcdir=aq0000020156

08/05/2021 10:08:01.684 I disconnect cmrpaq000002 tscomid=662,sesid=61533,fctkt=610a5801:1-f00a,fcdir=aq0000020156

08/05/2021 10:08:01.685 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:01.687 I request by t3rp22025 to notify disconnect of sesid=61533

08/05/2021 10:08:01.688 I statistics cmrpaq000002 sesid=61533,cpu=0.010s,dbms=0.000s,srv=0.021s

08/05/2021 10:08:02.415 I request by cmrpht000086 to POST u=OPSYSwf_admin,session=610a5801:1-ebb9, xcmd=Traces, page=BLANK

08/05/2021 10:08:02.431 I Default traces turned off for running server

08/05/2021 10:08:02.688 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:02.688 I connecting cmrpaq000002 tscomid=662,sesid=61534,fctkt=610a5801:1-f00b,fcdir=aq0000020157

08/05/2021 10:08:02.690 I disconnect cmrpaq000002 tscomid=662,sesid=61534,fctkt=610a5801:1-f00b,fcdir=aq0000020157

08/05/2021 10:08:02.690 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:02.690 I request by t3rp22025 to notify disconnect of sesid=61534

08/05/2021 10:08:02.690 I statistics cmrpaq000002 sesid=61534,cpu=0.000s,dbms=0.000s,srv=0.003s

08/05/2021 10:08:03.691 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:03.691 I connecting cmrpaq000002 tscomid=662,sesid=61535,fctkt=610a5801:1-f00c,fcdir=aq0000020158

08/05/2021 10:08:03.694 I disconnect cmrpaq000002 tscomid=662,sesid=61535,fctkt=610a5801:1-f00c,fcdir=aq0000020158

08/05/2021 10:08:03.694 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:03.694 I request by t3rp22025 to notify disconnect of sesid=61535

08/05/2021 10:08:03.694 I statistics cmrpaq000002 sesid=61535,cpu=0.000s,dbms=0.000s,srv=0.003s

08/05/2021 10:08:04.695 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:04.695 I connecting cmrpaq000002 tscomid=662,sesid=61536,fctkt=610a5801:1-f00d,fcdir=aq0000020159

08/05/2021 10:08:04.698 I disconnect cmrpaq000002 tscomid=662,sesid=61536,fctkt=610a5801:1-f00d,fcdir=aq0000020159

08/05/2021 10:08:04.698 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:04.698 I request by t3rp22025 to notify disconnect of sesid=61536

08/05/2021 10:08:04.698 I statistics cmrpaq000002 sesid=61536,cpu=0.000s,dbms=0.000s,srv=0.003s

08/05/2021 10:08:04.977 I request by cmrpht000086 to POST u=OPSYSwf_admin,session=610a5801:1-ebb9, page=WKSFRAMES

08/05/2021 10:08:04.983 I request by cmrpht000086 to POST u=OPSYSwf_admin,session=610a5801:1-ebb9, page=WKSRIBBON

08/05/2021 10:08:05.331 I request by cmrpht000086 to POST u=OPSYSwf_admin,session=610a5801:1-ebb9, page=CONFTREE

08/05/2021 10:08:05.335 I request by cmrpht000086 for explicit connect to agent (WC_DEFAULT)

08/05/2021 10:08:05.336 I connecting cmrpht000086 tscomid=649,sesid=61537,fctkt=610a5801:1-ebb9,fcdir=ht000080010

08/05/2021 10:08:05.336 I accepting cmrpht000087 tcp=192.168.40.200:9142

08/05/2021 10:08:05.337 I request by cmrpht000087 to POST u=OPSYSwf_admin,session=610a5801:1-ebb9, page=AGENTS

08/05/2021 10:08:05.339 I processing cmrpht000086 sesid=61537,u=OPSYSwf_admin,g=wf_admin,r=SRV

08/05/2021 10:08:05.459 I disconnect cmrpht000086 tscomid=649,sesid=61537,fctkt=610a5801:1-ebb9,fcdir=ht000080010

08/05/2021 10:08:05.459 I request by t3rp21964 to notify disconnect of sesid=61537

08/05/2021 10:08:05.459 I statistics cmrpht000086 sesid=61537,cpu=0.070s,dbms=0.001s,srv=0.100s

08/05/2021 10:08:05.698 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:05.699 I connecting cmrpaq000002 tscomid=662,sesid=61538,fctkt=610a5801:1-f00e,fcdir=aq0000020160

08/05/2021 10:08:05.701 I disconnect cmrpaq000002 tscomid=662,sesid=61538,fctkt=610a5801:1-f00e,fcdir=aq0000020160

08/05/2021 10:08:05.701 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:05.701 I request by t3rp22025 to notify disconnect of sesid=61538

08/05/2021 10:08:05.701 I statistics cmrpaq000002 sesid=61538,cpu=0.000s,dbms=0.000s,srv=0.003s

08/05/2021 10:08:06.702 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:06.706 I connecting cmrpaq000002 tscomid=662,sesid=61539,fctkt=610a5801:1-f00f,fcdir=aq000002010

08/05/2021 10:08:06.709 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:06.709 I disconnect cmrpaq000002 tscomid=662,sesid=61539,fctkt=610a5801:1-f00f,fcdir=aq000002010

08/05/2021 10:08:06.709 I request by t3rp22025 to notify disconnect of sesid=61539

08/05/2021 10:08:06.709 I statistics cmrpaq000002 sesid=61539,cpu=0.000s,dbms=0.000s,srv=0.008s

08/05/2021 10:08:07.709 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:07.709 I connecting cmrpaq000002 tscomid=662,sesid=61540,fctkt=610a5801:1-f010,fcdir=aq000002011

08/05/2021 10:08:07.712 I disconnect cmrpaq000002 tscomid=662,sesid=61540,fctkt=610a5801:1-f010,fcdir=aq000002011

08/05/2021 10:08:07.712 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:07.712 I request by t3rp22025 to notify disconnect of sesid=61540

08/05/2021 10:08:07.712 I statistics cmrpaq000002 sesid=61540,cpu=0.010s,dbms=0.000s,srv=0.003s

08/05/2021 10:08:08.180 I request by cmrpht000086 to POST u=OPSYSwf_admin,session=610a5801:1-ebb9, page=SDIAG

08/05/2021 10:08:08.713 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:08.713 I connecting cmrpaq000002 tscomid=662,sesid=61541,fctkt=610a5801:1-f011,fcdir=aq000002012

08/05/2021 10:08:08.715 I disconnect cmrpaq000002 tscomid=662,sesid=61541,fctkt=610a5801:1-f011,fcdir=aq000002012

08/05/2021 10:08:08.715 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:08.715 I request by t3rp22025 to notify disconnect of sesid=61541

08/05/2021 10:08:08.715 I statistics cmrpaq000002 sesid=61541,cpu=0.000s,dbms=0.000s,srv=0.003s

08/05/2021 10:08:09.716 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:09.716 I connecting cmrpaq000002 tscomid=662,sesid=61542,fctkt=610a5801:1-f012,fcdir=aq000002013

08/05/2021 10:08:09.718 I disconnect cmrpaq000002 tscomid=662,sesid=61542,fctkt=610a5801:1-f012,fcdir=aq000002013

08/05/2021 10:08:09.719 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:09.719 I request by t3rp22025 to notify disconnect of sesid=61542

08/05/2021 10:08:09.719 I statistics cmrpaq000002 sesid=61542,cpu=0.000s,dbms=0.000s,srv=0.003s

08/05/2021 10:08:10.719 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:10.720 I connecting cmrpaq000002 tscomid=662,sesid=61543,fctkt=610a5801:1-f013,fcdir=aq000002014

08/05/2021 10:08:10.722 I disconnect cmrpaq000002 tscomid=662,sesid=61543,fctkt=610a5801:1-f013,fcdir=aq000002014

08/05/2021 10:08:10.722 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:10.722 I request by t3rp22025 to notify disconnect of sesid=61543

08/05/2021 10:08:10.722 I statistics cmrpaq000002 sesid=61543,cpu=0.000s,dbms=0.000s,srv=0.003s

08/05/2021 10:08:11.723 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:11.723 I connecting cmrpaq000002 tscomid=662,sesid=61544,fctkt=610a5801:1-f014,fcdir=aq000002015

08/05/2021 10:08:11.725 I disconnect cmrpaq000002 tscomid=662,sesid=61544,fctkt=610a5801:1-f014,fcdir=aq000002015

08/05/2021 10:08:11.725 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:11.725 I request by t3rp22025 to notify disconnect of sesid=61544

08/05/2021 10:08:11.725 I statistics cmrpaq000002 sesid=61544,cpu=0.000s,dbms=0.000s,srv=0.003s

08/05/2021 10:08:12.726 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:12.726 I connecting cmrpaq000002 tscomid=662,sesid=61545,fctkt=610a5801:1-f015,fcdir=aq000002016

08/05/2021 10:08:12.728 I disconnect cmrpaq000002 tscomid=662,sesid=61545,fctkt=610a5801:1-f015,fcdir=aq000002016

08/05/2021 10:08:12.728 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:12.729 I request by t3rp22025 to notify disconnect of sesid=61545

08/05/2021 10:08:12.729 I statistics cmrpaq000002 sesid=61545,cpu=0.010s,dbms=0.000s,srv=0.003s

08/05/2021 10:08:13.729 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:13.729 I connecting cmrpaq000002 tscomid=662,sesid=61546,fctkt=610a5801:1-f016,fcdir=aq000002017

08/05/2021 10:08:13.732 I disconnect cmrpaq000002 tscomid=662,sesid=61546,fctkt=610a5801:1-f016,fcdir=aq000002017

08/05/2021 10:08:13.732 W dfm scan failed, postponed for 1 second

08/05/2021 10:08:13.732 I request by t3rp22025 to notify disconnect of sesid=61546

08/05/2021 10:08:13.732 I statistics cmrpaq000002 sesid=61546,cpu=0.000s,dbms=0.000s,srv=0.003s

08/05/2021 10:08:14.732 I request by cmrpaq000002 for explicit connect to agent (DEFAULT)

08/05/2021 10:08:14.733 I connecting cmrpaq000002 tscomid=662,sesid=61547,fctkt=610a5801:1-f017

[Nox Lee]

Hi,

Kinda figure out what cause deferred Report is queued, is because the report server is install on Linux and using OPSYS authentication to access, if I change to PTH everything work as in order. But I still need to know why using OPSYS is queued and how can I set for OPSYS to run deferred Report without queued

[Toby Mills]

Hi Nox,

Sounds like youre a little closer to figuring this out. Your edaprint.log has entries that I dont recognize (probably we are using different parts of the product).

The things I see that I dont typically see is the disconnect messages from cmrpaqxxxxx.

Typically I see cmrpip for client based IP connections and cmrpht for those of us hitting the server by using the HTTP based web console.

Not sure what aq is.

Anyway - only suggestion I can think of is to make sure your server is getting the users info. That would be controlled by your client Admin Console / Reporting Servers. Looks like this:

 

Youve got one spot in there where you can see the user ID being passed in and that came from the Reporting Server Console (notice the cmrpht)

08/05/2021 10:08:02.415 I request by cmrpht000086 to POST u=OPSYSwf_admin,session=610a5801:1-ebb9, xcmd=Traces, page=BLANK

It seems like maybe youre not passing your server credentials in right somehow.

Also look at your External Security in the Client Admin console. It should have a userID that can log in specified in there.

Also - if youve changed the order of your PTH / OPSYS access control providers - maybe switching from PTH to OPSYS as the primary - maybe thats a problem. By default, you dont have to specify the primary access control provider (like PTHwf_admin or OPSYSwf_admin). If you just say wf_admin, youll get whatever is the primary provider (this might be OPSYS for you).

Just be aware that the prefix before a user ID defaults to whatever is primary. If you want to log in with a secondary (like PTH for example), then you have to specify the PTH part.

Did you swap the order of access providers maybe

TIBCO support is probably your best bet to get it all ironed out. Id be curious to know what happened to close the loop on this thread.

[Nox Lee]

Hi Toby,

Im not so sure for those logs and I did raised a support from IBI tech support, hope I can get a better answer. After some testing with different OS of Reporting Server, that we find out that only Linux Report Server will queued Deferred Report with OPSYS authentication. So on Windows has no problem with OPSYS, I think something might have to so with Linuxs privilege.