Error DBUNLOAD V10

[ClaudiaWalter605077]

Hi,

we have the problem that our DBUNLOAD
"c:\Automic\V10\utility\bin>ucybdbun -BTRANSPORTALL -D -C100 -X..\db\transport_0100_save_MI.txt "
hung in the last run. The reason is unknown.
I aborted the JOBS, and when I try to restart I get the Error:
"Permission denied, can't create logfile ..\TEMP\ucybdbun_log_00.txt"

Has anyone an idea how to fix that?

[Frank Muffke]

Hi

usually this err message appears when a process uses (= writes to) the logfile.
Means that ucybdbun.exe is still writing into the logfile ..\TEMP\ucybdbun_log_00.txt

this can be caused by a db lock too => check Db unload logfile !!

=> kill / end the DB unload process and restart the job.

KR WOlfgang

------------------------------
Support Info:
if you are using one of the latest version of UC4 / AWA / One Automation please get in contact with Support to open a ticket.
Otherwise update/upgrade your system and check if the problem still exists.
------------------------------

[ClaudiaWalter605077]

Hi 

thank you for your immediate answer Wolfgang!
I will check the logfile. I didnt do that I have to admit.
I supposed it contains the same information like the report of the JOBS.

Meanwhile I restarted the JOBS for a 3 time an it worked!
We suppose that a Backup-job locked the file and will also investigate further.

Thank you very much!
Claudia

[Frank Muffke]

We suppose that a Backup-job locked the file and will also investigate further.

thats definitely a valid cause...

cheers, Wolfgang

------------------------------
Support Info:
if you are using one of the latest version of UC4 / AWA / One Automation please get in contact with Support to open a ticket.
Otherwise update/upgrade your system and check if the problem still exists.
------------------------------

[ClaudiaWalter605077]

I guess we found the cause...
but to me it's a bit strange..
I checked the logfile and it looks like
that dbunload went on working for at least half an hour after I aborted the Job doing the unload!

from 6:14h on the Jobs doing the unload hung.
at 9:51 I aborted the JOBS with the dbunload. the JOBS ended at 9:51h.

But  looking at the logfile, dbunload worked until 10:22h.
So this should be the reason why the logfile was in use !?

Logfile:
20191120/061430.541 - U0037032 0001572 - 20191114 REORG   ;OH,MELD,AH,RH,XAO
20191120/061430.541 - U0037032 0001573 - 20191115 REORG   ;OH,MELD,AH,RH,XAO
20191120/061430.541 - U0037032 0001574 - 20191116 REORG   ;OH,MELD,AH,RH,XAO
20191120/061430.556 - U0037032 0001575 - 20191117 REORG   ;OH,MELD,AH,RH,XAO
20191120/061430.556 - U0037032 0001576 - 20191118 REORG   ;OH,MELD,AH,RH,XAO
20191120/061430.556 - U0037032 0001577 - 20191119 REORG   ;OH,MELD,AH,RH,XAO
20191120/061430.556 - U0037111 Starting reorganization for client: 'ALL'
20191120/100747.722 - U0003524 UCUDB: ===> Time critical DB call!       OPC: 'EXEC' time: '13997:109.278.399'
20191120/100747.722 - U0003525 UCUDB: ===> 'ALTER TABLE DIVDB ACTIVATE NOT LOGGED INITIALLY WITH EMPTY TABLE'
20191120/100754.056 - U0011667 Count of records in 'MELD' = '28971'
20191120/100754.056 - U0037110 Delete records from table 'MELD' / progress '100'%
20191120/100754.056 - U0037172 Finished cleanup of Table Meld
.......
......
20191120/102200.720 - U0003525 UCUDB: ===> 'delete from AH where AH_idnr in (select DIVDB_PK from DIVDB)'
20191120/102200.845 - U0011667 Count of records in 'AH' = '75549'
20191120/102200.845 - U0037110 Delete records from table 'AH' / progress '100'%
20191120/102200.845 - U0037167 Finished cleanup of Table AH.
20191120/102201.110 - U0011667 Count of records in 'XAO' = '6'
20191120/102201.110 - U0037110 Delete records from table 'XAO' / progress '100'%
20191120/102201.110 - U0037162 Finished cleanup of Table XAO.
20191120/102201.141 - U0003523 UCUDB: Maximum time required for a DB call: '13997:109.278.399'.
20191120/102201.141 - U0003522 UCUDB: Database closed. Total time for DB calls: '14854:537.247.999' seconds.
20191120/102201.141 - U0003549 UCUDB: '            1003' 'OTHERS    ' calls took '4:010.083.500' sec.
20191120/102201.141 - U0003549 UCUDB: '              14' 'SELECT    ' calls took '0:740.817.999' sec.
20191120/102201.141 - U0003549 UCUDB: '            2529' 'EXECUTE   ' calls took '14845:924.804.199' sec.
20191120/102201.141 - U0003549 UCUDB: '               0' 'UPDATE    ' calls took '0:000.000.000' sec.
20191120/102201.141 - U0003549 UCUDB: '               0' 'DELETE    ' calls took '0:000.000.000' sec.
20191120/102201.141 - U0003549 UCUDB: '               1' 'INSERT    ' calls took '0:001.937.700' sec.
20191120/102201.141 - U0003549 UCUDB: '            1818' 'READ      ' calls took '0:027.545.999' sec.
20191120/102201.141 - U0003549 UCUDB: '            3790' 'CLOSESTMT ' calls took '0:005.475.800' sec.
20191120/102201.141 - U0003549 UCUDB: '             510' 'TRANSACT  ' calls took '3:826.582.800' sec.

[Carsten Schmitz]

Makes sense.

As I see it, Automic does not really guarantee that it aborts the OS process when you abort a job in the UI.

Quite on the contrary, the agent goes to great length to start OS processes (such as your unload) in a way so they keep running even if the agent should die.

Also, in some cases it would be either impossible to do so or rather messy, e.g. a UNIX process that is in Zombie state or that has been disowned by its controlling process and taken over by init could not be terminated by the original process, i.e. Automic. And I hear the occasional Windows process that doesn't immediately react to signals to terminate isn't unheard of either ...

[Carsten Schmitz]

​So this should be the reason why the logfile was in use !?

Likely, yes. If in doubt, I recommend using a tool such as Mark Russinovichs Sysinternals (now Microsoft) Process Monitor, which is basically "lsof" for Windows. It can tell you what process has specific files open at any given time.

[Alain Moisy]

Some additional possibilities :

- first attempt was that another DBUnload was running on the same server => tries to create the same log file already in use and can't do it

- you use the -D option to remove the entries in the transport container. Depending how you cancel the job and process there is maybe a backout on update transactions and it takes time if you ahve a lot of entries. And during that time, the process is not considered as ended on the DB side.

- you can also have a conflict of authorisations between the user starting the job, the account in the Login object, the user that issue the cancel command, the authorization of the Agent to issue a cancel command on the process activated by another user, .... So many places where something can be blocked, denied or simply put in a waiting state .

Just to put more confusion in something already strange =-)

Alain

[ClaudiaWalter605077]

yes, really strange ;-)​

I prefer the attempt with still running db-activity.
  
Although I would have expected the JOBS not to end before db-activity is finished.
But it seems as if it is like that.

Thank you!!