Pharos - Logon cancelled by plug-in

Working with Pharos 8.1 on Windows 2008 R2 configured to use AD Authentication. Pharos clients are getting "Print job 'Untitled - Notepad' failed: Logon cancelled by plug-in" popup message after correctly entering valid credentials.

Pharos Client popup - Logon Cancelled by Plug-in

Looking at the alert error from in "Pharos Administrator -> System -> Alerts" doesn't show a lot more information as to the cause of the message.

Pharos - Pharos Admin Alert for Logon Cancelled by plug-in

To get more information we have to enable the Pharos Print Server logs. To do this follow my other post on how to enable the Pharos Print Server Logging. Once that is done and the Pharos Print Server has been restarted so logging changes take effect, print from the client again which should cause the "Logon cancelled by plug-in" error again and then look at the log.



My Pharos Print Server log shows the follow.

[2011/02/11 15:02:44] Initalizing Task Thread ..
[2011/02/11 15:02:44]
[2011/02/11 15:02:44] PrintJobArrive ps error: Logon cancelled by plug-in
[2011/02/11 15:02:44] PrintJobArrive cancel job: 1
[2011/02/11 15:02:44] [CPrintJob::Cancel] Job<23> Record Cancellation: deleted=1 CancellationCategory=1
[2011/02/11 15:02:44] [CPrintJob::Cancel] Job<1889542861> Failed to fetch cache data from job

To get more details I changed the logging settings with logsetter to include debug message at level 5 (max) and under advance check to "show category". Following that I stopped the Pharos Print Server Service, delete the log file, started the service. This makes searching the log much easier.

However its really still to much information to look thought by hand. When we enabled "show category" it gave us a way to filter out the debug entires we didn't want. I then use LogExpert search and fitler the log. Filter on text CPS and check "Inverted Match".

Pharos - LogExpert of Pharos Print Server Log

The Pharos Print Server Log now if filtered correctly should look i lot more readable like the following.

[2011/02/11 15:14:32] Jobs in queues [1]
[2011/02/11 15:14:32] Job<31> JOB_NOTIFY_FIELD_USER_NAME: SYSTEM
[2011/02/11 15:14:32] Job<31> JOB_NOTIFY_FIELD_STATUS: 8
[2011/02/11 15:14:32] Job<31> JOB_NOTIFY_FIELD_DOCUMENT: Local Downlevel Document
[2011/02/11 15:14:32] Job<31> JOB_NOTIFY_FIELD_SUBMITTED
[2011/02/11 15:14:32] Job<31> JOB_NOTIFY_FIELD_USER_NAME: towlesd
[2011/02/11 15:14:32] Job<31> JOB_NOTIFY_FIELD_DOCUMENT: Untitled - Notepad
[2011/02/11 15:14:32] Job<31> JOB_NOTIFY_FIELD_STATUS: 0
[2011/02/11 15:14:32] Job<31> JOB ARRIVAL COMPLETE: create job arrival task
[2011/02/11 15:14:32] Parse job properties, attributes = Unknown
[2011/02/11 15:14:32] Loaded Regex ([ ]*[(])([^)]+)([)].*)
[2011/02/11 15:14:32] Loaded Regex ([ ]*)([^ (]+)(.*)
[2011/02/11 15:14:32] [CPVerbs::Init] => Client [ :: ]
[2011/02/11 15:14:32] Script 'NotifyU' created, size = 805
[2011/02/11 15:14:32] Script 'NKU Print Job' created, size = 2556
[2011/02/11 15:14:32] [CPVerbs::Init] => Bank [ADLDAP Bank]
[2011/02/11 15:14:32] Script 'NKU with Multiple Purses' created, size = 12866
[2011/02/11 15:14:32] [CTaskThread::OnTask]  Go and fetch a new task
[2011/02/11 15:14:32] [CTaskManager::GetTask] Get new task to process <1>
[2011/02/11 15:14:32] [CTaskThread::OnTask]  execute task <PrintJobArrive>
[2011/02/11 15:14:32] CIgnorePrintJobsOnArrival::Ignore   JobID=31  ltime=-2028435341  => 9109532
[2011/02/11 15:14:32] Job<31> JOB_NOTIFY_FIELD_TOTAL_BYTES: 34136
[2011/02/11 15:14:32] [CPVerbs::Init] => Client [ :: ]
[2011/02/11 15:14:32] Script 'NotifyU' created, size = 805
[2011/02/11 15:14:32] Script 'NKU Print Job' created, size = 2556
[2011/02/11 15:14:32] [CPVerbs::Init] => Bank [ADLDAP Bank]
[2011/02/11 15:14:32] Script 'NKU with Multiple Purses' created, size = 12866
[2011/02/11 15:14:32] Regex 1 matched 'towlesd' as 'towlesd'
[2011/02/11 15:14:32] [CBankPlugIn::Logon] level = User, username = towlesd, client =
[2011/02/11 15:14:32] [CPlugIn::Execute] Create Process
[2011/02/11 15:14:32] [CPlugIn::Execute] Create handles to capture output
[2011/02/11 15:14:32] [CPlugIn::Execute] Wait for process to exit
[2011/02/11 15:14:32] [CPlugIn::Execute] exit 1
[2011/02/11 15:14:32] Logon plug-in result is ''
[2011/02/11 15:14:32] PrintJobArrive ps error: Logon cancelled by plug-in
[2011/02/11 15:14:32] PrintJobArrive cancel job: 1
[2011/02/11 15:14:32] Job<31> JOB_NOTIFY_FIELD_PENDING_CANCELLATION: 1
[2011/02/11 15:14:32] Change event: PRINTER_CHANGE_DELETE_JOB

Thats way more readable. Looking at the order it comes down that Logon plug-in result is '' is the result from Logon plug-in. That means the bank is actually the problem. You can check what bank is selected and having the problem by Looking in "Pharos Administrator ->  System -> Print Server -> Bank".

With that we have narrowed down the cause of  "Logon cancelled by plug-in" is actually a problem with the Pharos Bank being used. Look into testing your bank. If you are using the ADLDAP Bank read my other post here on how to test and configure it.