Failed to create semaphore [-1]

Last post 03-28-2019, 5:59 AM by macmecki. 17 replies.
Sort Posts: Previous Next
  • Failed to create semaphore [-1]
    Posted: 03-25-2019, 9:45 AM

    Hello,

    on one linux system we ever get this message and it go to pending.

    Error Code: [19:1335] Description: Oracle Backup [Job[1569509] thread[11544]: Unable to contact the client..] Source: lxntxbbz, Process: ORASBT

    Can erverybody help me ?

     

    regards

    Chris

  • Re: Failed to create semaphore [-1]
    Posted: 03-25-2019, 5:54 PM

    Hi Chris

    If you putty onto the Client and navigate to the Log_Directory and "# tail -100 orasbt.log", are their additional errors. 

    Logging from the client itself might give you a better insight to the cause of the issue. 

    Otherwise you can also share the log file so we can take a look as well

    Regards

    Winston

  • Re: Failed to create semaphore [-1]
    Posted: 03-26-2019, 4:46 AM

    here i've first the last lines of the RMAN-Log from the job.

    input archived log thread=1 sequence=55125 RECID=55102 STAMP=1003636908
    input archived log thread=1 sequence=55126 RECID=55103 STAMP=1003637106
    channel ch1: starting piece 1 at Mar 26 2019 09:20:56
    released channel: ch1
    RMAN-00571: ===========================================================
    RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
    RMAN-00571: ===========================================================
    RMAN-03009: failure of backup command on ch1 channel at 03/26/2019 09:20:57
    ORA-19506: failed to create sequential file, name="1569923_NTX_bgttd1vn_1_1", parms=""
    ORA-27028: skgfqcre: sbtbackup returned error
    ORA-19511: Error received from media manager layer, error text:
    CreateOraObject20: Job[1569923] thread[16955]: Unable to contact the client..
    RMAN>
    Recovery Manager complete.
     
    And the log you ask was empty.
    <servername>:/var/log/commvault/Log_Files # tail -100 ORASBT.log
  • Re: Failed to create semaphore [-1]
    Posted: 03-26-2019, 7:28 AM

    Hi macmecki

    Thank you for sharing the logs 

    The error from the RMAN logs looks like it is failing to execute the RMAN script

    Might be advisable to open a support ticket to review the end to end connection and confirm the root cause. 

    Regards

    Winston 

  • Re: Failed to create semaphore [-1]
    Posted: 03-26-2019, 8:20 AM

    Hi Winston,

    Can I control myself whether the RMAN script can be executed and which rights the script has?
    Where would that have to be?
  • Re: Failed to create semaphore [-1]
    Posted: 03-26-2019, 9:50 AM
    • efg is not online. Last active: 05-24-2019, 9:36 AM efg
    • Top 10 Contributor
    • Joined on 02-02-2010
    • CommVault Tinton Falls NJ
    • Expert
    • Points 1,656

    This error appears to indicate a problem where the Media Agent is having a problem connecting back to the client through the SBT layer.   This could be due to a problem connecting through the network, or if there are problems creating the semaphore on the client to receive the connect request.  This may require a support ticket to better trouble shoot, but a couple quick questions...   Have the backups ever worked for this client?  Is this error persistent, or do the backups sometimes work (it the problem intermittent?)  Can you test connectivity between the media agent server and this oracle client?  Also you may want to check out the cvd.log on the mediaagent at the time the error occurs as there may be more information with regards to connectivity issues.  Also I find it odd that the ORASBT.log was empty as when the SBT layer is accessed (through the libobk/SBT library) it should start logging to this file immediately.  

    Also is this a unix type system or a windows server?  From the "tail" command it appears to be Unix, so can you expand on the platform?  as to whether its Linux or AIX or Solaris?


    Ernst F. Graeler
    Senior Engineer III
    Development
  • Re: Failed to create semaphore [-1]
    Posted: 03-26-2019, 10:11 AM
    The backups for this client worked flawlessly until 2 weeks ago?
    As far as known, no changes were made to the system, only on our Commvault environment was updated to V11 SP15. But that should not change anything.
    The server is a Linux system, Commvault on Windows server.
    Ping works in all directions.
    I suspect that it is somehow due to Oracle RMAN, but I'm not informed enough.
     
    Here are Tail -100 cvd.log
    lxntxbbz:/var/log/commvault/Log_Files # tail -100 cvd.log
    28672 7025 03/26 13:56:44 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.051354]s, Time (Parallel) [0.050283]s, Wait [0.000416]s
    28672 7025 03/26 14:01:44 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.050473]s, Time (Parallel) [0.049120]s, Wait [0.000489]s
    28672 47c9 03/26 14:06:44 --- CCVDSpaceCheck::CleanupIdleEventConnections() - Invoking CleanUp Idle Event Connections.
    28672 47c9 03/26 14:06:44 ### periodicallyCleanUpIdleEventConnections() - CleanUpIdleEventConnections started
    28672 47ca 03/26 14:06:44 ### CCVDSpaceCheckTimer::SpaceCheckTaskCallback() - Ransomware Check Status: Success
    28672 7025 03/26 14:06:44 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.050578]s, Time (Parallel) [0.049473]s, Wait [0.000419]s
    28672 47cc 03/26 14:06:45 ### CVClientPerformanceHistory::SendPerfLogFilesToCS() - ANNAK10:Not Media Agent with needed roles and not a CommServer. Will not upload PerfLog System files.
    28672 47cd 03/26 14:06:45 --- additionalSettingsRefresh() - Cleaning temporary key.
    28672 7025 03/26 14:11:44 ### TPool [N/A]. Ser# [1] Tot Devil [6], Pend [0], Comp Devil [6], Max Par [5], Time (Serial) [2.189314]s, Time (Parallel) [1.072334]s, Wait [0.000857]s
    28672 7025 03/26 14:16:44 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.045487]s, Time (Parallel) [0.043891]s, Wait [0.000414]s
    28672 7025 03/26 14:21:44 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.046529]s, Time (Parallel) [0.044596]s, Wait [0.000340]s
    28672 5841 03/26 14:26:44 --- CCVDSpaceCheck::CleanupIdleEventConnections() - Invoking CleanUp Idle Event Connections.
    28672 5841 03/26 14:26:44 ### periodicallyCleanUpIdleEventConnections() - CleanUpIdleEventConnections started
    28672 7025 03/26 14:26:44 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.046996]s, Time (Parallel) [0.045412]s, Wait [0.000418]s
    28672 5d2e 03/26 14:31:43 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", ""/opt/commvault/iDataAgent/ClOraAgent" DBSTATUS -a 2:1797 -cn lxntxbbz -vm Instance001".
    28672 5d2e 03/26 14:31:43 ### [CVipcD] Remote Command Request from remotehost = <commserve.mn.freinet.de>. Launched Process: <"/opt/commvault/iDataAgent/ClOraAgent" DBSTATUS -a 2:1797 -cn lxntxbbz -vm Instance001>. Pid=23856
    28672 7025 03/26 14:31:44 ### TPool [N/A]. Ser# [0] Tot [1], Pend [0], Comp [1], Max Par [1], Time (Serial) [0.000471]s, Time (Parallel) [0.000471]s, Wait [0.000064]s
    28672 7025 03/26 14:31:44 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.045793]s, Time (Parallel) [0.044061]s, Wait [0.000411]s
    28672 5d46 03/26 14:31:47 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", ""/opt/commvault/iDataAgent/ClOraAgent" BACKUP 2 -PREVIEW -data -taskId 1570087 -j 1570087 -a 2:1797 -t 2 -sequence 4436701236900 -cn lxntxbbz -vm Instance001".
    28672 5d46 03/26 14:31:47 ### [CVipcD] Remote Command Request from remotehost = <commserve.mn.freinet.de>. Launched Process: <"/opt/commvault/iDataAgent/ClOraAgent" BACKUP 2 -PREVIEW -data -taskId 1570087 -j 1570087 -a 2:1797 -t 2 -sequence 4436701236900 -cn lxntxbbz -vm Instance001>. Pid=23880
    28672 5d66 03/26 14:31:48 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", ""/opt/commvault/iDataAgent/ClOraAgent" BACKUP 2 -PREVIEW -logs -taskId 1570087 -j 1570087 -a 2:1797 -t 2 -sequence 4436701236900 -cn lxntxbbz -vm Instance001".
    28672 5d66 03/26 14:31:48 ### [CVipcD] Remote Command Request from remotehost = <commserve.mn.freinet.de>. Launched Process: <"/opt/commvault/iDataAgent/ClOraAgent" BACKUP 2 -PREVIEW -logs -taskId 1570087 -j 1570087 -a 2:1797 -t 2 -sequence 4436701236900 -cn lxntxbbz -vm Instance001>. Pid=23912
    28672 5f84 03/26 14:34:12 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", ""/opt/commvault/iDataAgent/ClOraAgent" BACKUP 2 -PREVIEW -data -taskId 1570088 -j 1570088 -a 2:1797 -t 2 -sequence 4436701236902 -cn lxntxbbz -vm Instance001".
    28672 5f84 03/26 14:34:12 ### [CVipcD] Remote Command Request from remotehost = <commserve.mn.freinet.de>. Launched Process: <"/opt/commvault/iDataAgent/ClOraAgent" BACKUP 2 -PREVIEW -data -taskId 1570088 -j 1570088 -a 2:1797 -t 2 -sequence 4436701236902 -cn lxntxbbz -vm Instance001>. Pid=24454
    28672 5fa7 03/26 14:34:14 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", ""/opt/commvault/iDataAgent/ClOraAgent" BACKUP 2 -PREVIEW -logs -taskId 1570088 -j 1570088 -a 2:1797 -t 2 -sequence 4436701236902 -cn lxntxbbz -vm Instance001".
    28672 5fa7 03/26 14:34:14 ### [CVipcD] Remote Command Request from remotehost = <commserve.mn.freinet.de>. Launched Process: <"/opt/commvault/iDataAgent/ClOraAgent" BACKUP 2 -PREVIEW -logs -taskId 1570088 -j 1570088 -a 2:1797 -t 2 -sequence 4436701236902 -cn lxntxbbz -vm Instance001>. Pid=24489
    28672 6079 03/26 14:35:14 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", "ClOraAgent -restart BACKUP -j 1570089 -a 2:1797 -t 1 -jt 1570089:4:1 -data -d NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -idxma NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -cn lxntxbbz -vm Instance001".
    28672 6079 03/26 14:35:14 ### [CVipcD] Remote Command Request from remotehost = <127.0.0.1>. Launched Process: <ClOraAgent -restart BACKUP -j 1570089 -a 2:1797 -t 1 -jt 1570089:4:1 -data -d NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -idxma NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -cn lxntxbbz -vm Instance001>. Pid=24699
    28672 7024 03/26 14:35:15 ### [CVipcD] Successfully registered control process for Job [JobID:[1570089],Phase:[4],Attempt:[1]] of type [1].
    28672 702c 03/26 14:35:23 ### CvFwPull() - Got certificate/key request from DB engine
    28672 700a 03/26 14:35:24 ### checkEventSocket() - setupConnection to EvMgrS...
    28672 674 03/26 14:35:24 ### CCvNetworkServer::ReadThread() - Could not peek for data format. Error:'0x80070306:{CCvNetwork::PeekDataFormat(5839)} + {CCvNetwork::ReceiveXDRMessage(5062)/W32.774.(Unknown error 774)-Bad state Devil [6] for data transfer}', timedOut:No, handle:42
    28672 700a 03/26 14:35:24 ### ::respond() - Responding to Challenge
    28672 700a 03/26 14:35:24 ### ::UserLogin() - Application Login for cvd
    28672 700a 03/26 14:35:24 ### checkEventSocket() - Socket [20]: is eventSocket
    28672 7025 03/26 14:36:44 ### TPool [N/A]. Ser# [0] Tot [2], Pend [0], Comp [2], Max Par [1], Time (Serial) [0.031874]s, Time (Parallel) [0.031874]s, Wait [0.000165]s
    28672 7025 03/26 14:36:44 ### TPool [JobControlCVD]. Ser# [0] Tot [4], Pend [0], Comp [4], Max Par [1], Time (Serial) [0.387466]s, Time (Parallel) [0.387466]s, Wait [0.000406]s
    28672 7025 03/26 14:36:44 ### TPool [JobControlCVD]. Ser# [1] Tot [9], Pend [0], Comp [9], Max Par [1], Time (Serial) [0.002481]s, Time (Parallel) [0.002481]s, Wait [0.000875]s
    28672 7025 03/26 14:36:44 ### TPool [N/A]. Ser# [0] Tot [2], Pend [0], Comp [2], Max Par [1], Time (Serial) [0.000401]s, Time (Parallel) [0.000401]s, Wait [0.000125]s
    28672 7025 03/26 14:36:44 ### TPool [N/A]. Ser# [0] Tot [5], Pend [0], Comp [5], Max Par [1], Time (Serial) [0.003221]s, Time (Parallel) [0.003221]s, Wait [0.000478]s
    28672 7025 03/26 14:36:44 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.053093]s, Time (Parallel) [0.052389]s, Wait [0.000204]s
    28672 63c9 03/26 14:39:50 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", ""/opt/commvault/iDataAgent/ClOraAgent" DBSTATUS -a 2:1797 -cn lxntxbbz -vm Instance001".
    28672 63c9 03/26 14:39:50 ### [CVipcD] Remote Command Request from remotehost = <commserve.mn.freinet.de>. Launched Process: <"/opt/commvault/iDataAgent/ClOraAgent" DBSTATUS -a 2:1797 -cn lxntxbbz -vm Instance001>. Pid=25547
    28672 63ee 03/26 14:39:59 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", "ClOraAgent BACKUP -j 1570090 -a 2:1797 -t 32768 -jt 1570090:4:1 -data -d NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -idxma NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -cn lxntxbbz -vm Instance001".
    28672 63ee 03/26 14:39:59 ### [CVipcD] Remote Command Request from remotehost = <127.0.0.1>. Launched Process: <ClOraAgent BACKUP -j 1570090 -a 2:1797 -t 32768 -jt 1570090:4:1 -data -d NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -idxma NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -cn lxntxbbz -vm Instance001>. Pid=25584
    28672 7024 03/26 14:40:00 ### [CVipcD] Successfully registered control process for Job [JobID:[1570090],Phase:[4],Attempt:[1]] of type [1].
    28672 702c 03/26 14:40:04 ### CvFwPull() - Got certificate/key request from DB engine
    28672 674 03/26 14:40:04 ### CCvNetworkServer::ReadThread() - Could not peek for data format. Error:'0x80070306:{CCvNetwork::PeekDataFormat(5839)} + {CCvNetwork::ReceiveXDRMessage(5062)/W32.774.(Unknown error 774)-Bad state Devil [6] for data transfer}', timedOut:No, handle:46
    28672 7025 03/26 14:41:44 ### TPool [N/A]. Ser# [0] Tot [2], Pend [0], Comp [2], Max Par [1], Time (Serial) [0.010321]s, Time (Parallel) [0.010321]s, Wait [0.000189]s
    28672 7025 03/26 14:41:44 ### TPool [JobControlCVD]. Ser# [0] Tot [4], Pend [0], Comp [4], Max Par [1], Time (Serial) [0.386735]s, Time (Parallel) [0.386735]s, Wait [0.000469]s
    28672 7025 03/26 14:41:44 ### TPool [JobControlCVD]. Ser# [1] Tot [9], Pend [0], Comp [9], Max Par [1], Time (Serial) [0.001606]s, Time (Parallel) [0.001606]s, Wait [0.000860]s
    28672 7025 03/26 14:41:44 ### TPool [N/A]. Ser# [0] Tot [2], Pend [0], Comp [2], Max Par [1], Time (Serial) [0.000426]s, Time (Parallel) [0.000426]s, Wait [0.000091]s
    28672 7025 03/26 14:41:44 ### TPool [N/A]. Ser# [0] Tot [2], Pend [0], Comp [2], Max Par [1], Time (Serial) [0.001569]s, Time (Parallel) [0.001569]s, Wait [0.000248]s
    28672 7025 03/26 14:41:44 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.049619]s, Time (Parallel) [0.048061]s, Wait [0.000480]s
    28672 681c 03/26 14:42:48 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", ""/opt/commvault/iDataAgent/ClOraAgent" DBSTATUS -a 2:1797 -cn lxntxbbz -vm Instance001".
    28672 681c 03/26 14:42:48 ### [CVipcD] Remote Command Request from remotehost = <commserve.mn.freinet.de>. Launched Process: <"/opt/commvault/iDataAgent/ClOraAgent" DBSTATUS -a 2:1797 -cn lxntxbbz -vm Instance001>. Pid=26654
    28672 6844 03/26 14:43:00 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", "ClOraAgent -restart BACKUP -j 1570091 -a 2:1799 -t 1 -logs -jt 1570091:5:1 -d NTBACKUP2.mn.freinet.de*ntbackup2*8400*8402 -idxma NTBACKUP2.mn.freinet.de*ntbackup2*8400*8402 -cn lxntxbbz -vm Instance001".
    28672 6844 03/26 14:43:00 ### [CVipcD] Remote Command Request from remotehost = <127.0.0.1>. Launched Process: <ClOraAgent -restart BACKUP -j 1570091 -a 2:1799 -t 1 -logs -jt 1570091:5:1 -d NTBACKUP2.mn.freinet.de*ntbackup2*8400*8402 -idxma NTBACKUP2.mn.freinet.de*ntbackup2*8400*8402 -cn lxntxbbz -vm Instance001>. Pid=26694
    28672 7024 03/26 14:43:01 ### [CVipcD] Successfully registered control process for Job [JobID:[1570091],Phase:[5],Attempt:[1]] of type [1].
    28672 702c 03/26 14:43:06 ### CvFwPull() - Got certificate/key request from DB engine
    28672 674 03/26 14:43:06 ### CCvNetworkServer::ReadThread() - Could not peek for data format. Error:'0x80070306:{CCvNetwork::PeekDataFormat(5839)} + {CCvNetwork::ReceiveXDRMessage(5062)/W32.774.(Unknown error 774)-Bad state Devil [6] for data transfer}', timedOut:No, handle:50
    28672 6c52 03/26 14:45:36 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", ""/opt/commvault/iDataAgent/ClOraAgent" DBSTATUS -a 2:1797 -cn lxntxbbz -vm Instance001".
    28672 6c52 03/26 14:45:36 ### [CVipcD] Remote Command Request from remotehost = <commserve.mn.freinet.de>. Launched Process: <"/opt/commvault/iDataAgent/ClOraAgent" DBSTATUS -a 2:1797 -cn lxntxbbz -vm Instance001>. Pid=27732
    28672 6cf8 03/26 14:45:45 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", "ClOraAgent -restart BACKUP -j 1570092 -a 2:1797 -t 1 -jt 1570092:4:1 -data -d NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -idxma NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -cn lxntxbbz -vm Instance001".
    28672 6cf8 03/26 14:45:45 ### [CVipcD] Remote Command Request from remotehost = <127.0.0.1>. Launched Process: <ClOraAgent -restart BACKUP -j 1570092 -a 2:1797 -t 1 -jt 1570092:4:1 -data -d NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -idxma NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -cn lxntxbbz -vm Instance001>. Pid=27898
    28672 7024 03/26 14:45:46 ### [CVipcD] Successfully registered control process for Job [JobID:[1570092],Phase:[4],Attempt:[1]] of type [1].
    28672 702c 03/26 14:45:50 ### CvFwPull() - Got certificate/key request from DB engine
    28672 674 03/26 14:45:50 ### CCvNetworkServer::ReadThread() - Could not peek for data format. Error:'0x80070306:{CCvNetwork::PeekDataFormat(5839)} + {CCvNetwork::ReceiveXDRMessage(5062)/W32.774.(Unknown error 774)-Bad state Devil [6] for data transfer}', timedOut:No, handle:54
    28672 6d6b 03/26 14:46:44 --- CCVDSpaceCheck::CleanupIdleEventConnections() - Invoking CleanUp Idle Event Connections.
    28672 6d6b 03/26 14:46:44 ### periodicallyCleanUpIdleEventConnections() - CleanUpIdleEventConnections started
    28672 7025 03/26 14:46:44 ### TPool [N/A]. Ser# [0] Tot [4], Pend [0], Comp [4], Max Par [1], Time (Serial) [0.020735]s, Time (Parallel) [0.020735]s, Wait [0.000416]s
    28672 7025 03/26 14:46:44 ### TPool [JobControlCVD]. Ser# [0] Tot Music [8], Pend [0], Comp Music [8], Max Par [1], Time (Serial) [0.786310]s, Time (Parallel) [0.786310]s, Wait [0.000829]s
    28672 7025 03/26 14:46:44 ### TPool [JobControlCVD]. Ser# [1] Tot [18], Pend [0], Comp [18], Max Par [1], Time (Serial) [0.002920]s, Time (Parallel) [0.002920]s, Wait [0.001713]s
    28672 7025 03/26 14:46:44 ### TPool [N/A]. Ser# [0] Tot [4], Pend [0], Comp [4], Max Par [1], Time (Serial) [0.000830]s, Time (Parallel) [0.000830]s, Wait [0.000186]s
    28672 7025 03/26 14:46:44 ### TPool [N/A]. Ser# [0] Tot [4], Pend [0], Comp [4], Max Par [1], Time (Serial) [0.003108]s, Time (Parallel) [0.003108]s, Wait [0.000485]s
    28672 7025 03/26 14:46:44 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.052747]s, Time (Parallel) [0.051628]s, Wait [0.000420]s
    28672 7025 03/26 14:51:44 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.048688]s, Time (Parallel) [0.047159]s, Wait [0.000427]s
    28672 7025 03/26 14:56:44 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.047159]s, Time (Parallel) [0.046097]s, Wait [0.000416]s
    28672 7c8d 03/26 15:01:14 ### ::ProcessWorkQueueRequest() - Successfully processed WorkQueue request on the client.
    28672 7ca2 03/26 15:01:43 ### ::ProcessWorkQueueRequest() - Successfully processed WorkQueue request on the client.
    28672 7025 03/26 15:01:45 ### TPool [N/A]. Ser# [0] Tot [2], Pend [0], Comp [2], Max Par [1], Time (Serial) [0.001596]s, Time (Parallel) [0.001596]s, Wait [0.000270]s
    28672 7025 03/26 15:01:45 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.051293]s, Time (Parallel) [0.050065]s, Wait [0.000378]s
    28672 7f55 03/26 15:05:27 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", ""/opt/commvault/iDataAgent/ClOraAgent" DBSTATUS -a 2:1797 -cn lxntxbbz -vm Instance001".
    28672 7f55 03/26 15:05:27 ### [CVipcD] Remote Command Request from remotehost = <commserve.mn.freinet.de>. Launched Process: <"/opt/commvault/iDataAgent/ClOraAgent" DBSTATUS -a 2:1797 -cn lxntxbbz -vm Instance001>. Pid=32599
    28672 7f6c 03/26 15:05:37 ### CvProcess::StartProcess() - Launching "/opt/commvault/iDataAgent/ClOraAgent", "ClOraAgent -restart BACKUP -j 1570098 -a 2:1797 -t 1 -jt 1570098:4:1 -data -d NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -idxma NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -cn lxntxbbz -vm Instance001".
    28672 7f6c 03/26 15:05:37 ### [CVipcD] Remote Command Request from remotehost = <127.0.0.1>. Launched Process: <ClOraAgent -restart BACKUP -j 1570098 -a 2:1797 -t 1 -jt 1570098:4:1 -data -d NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -idxma NTBACKUP1.mn.freinet.de*ntbackup1*8400*8402 -cn lxntxbbz -vm Instance001>. Pid=32622
    28672 7024 03/26 15:05:38 ### [CVipcD] Successfully registered control process for Job [JobID:[1570098],Phase:[4],Attempt:[1]] of type [1].
    28672 702c 03/26 15:05:41 ### CvFwPull() - Got certificate/key request from DB engine
    28672 674 03/26 15:05:42 ### CCvNetworkServer::ReadThread() - Could not peek for data format. Error:'0x80070306:{CCvNetwork::PeekDataFormat(5839)} + {CCvNetwork::ReceiveXDRMessage(5062)/W32.774.(Unknown error 774)-Bad state Devil [6] for data transfer}', timedOut:No, handle:58
    28672 7fd4 03/26 15:06:44 --- CCVDSpaceCheck::CleanupIdleEventConnections() - Invoking CleanUp Idle Event Connections.
    28672 7fd4 03/26 15:06:44 ### periodicallyCleanUpIdleEventConnections() - CleanUpIdleEventConnections started
    28672 7025 03/26 15:06:45 ### TPool [N/A]. Ser# [0] Tot [2], Pend [0], Comp [2], Max Par [1], Time (Serial) [0.033226]s, Time (Parallel) [0.033226]s, Wait [0.000250]s
    28672 7025 03/26 15:06:45 ### TPool [JobControlCVD]. Ser# [0] Tot [4], Pend [0], Comp [4], Max Par [1], Time (Serial) [0.382012]s, Time (Parallel) [0.382012]s, Wait [0.000370]s
    28672 7025 03/26 15:06:45 ### TPool [JobControlCVD]. Ser# [1] Tot [9], Pend [0], Comp [9], Max Par [1], Time (Serial) [0.001850]s, Time (Parallel) [0.001850]s, Wait [0.001049]s
    28672 7025 03/26 15:06:45 ### TPool [N/A]. Ser# [0] Tot [2], Pend [0], Comp [2], Max Par [1], Time (Serial) [0.000433]s, Time (Parallel) [0.000433]s, Wait [0.000196]s
    28672 7025 03/26 15:06:45 ### TPool [N/A]. Ser# [0] Tot [2], Pend [0], Comp [2], Max Par [1], Time (Serial) [0.001489]s, Time (Parallel) [0.001489]s, Wait [0.000252]s
    28672 7025 03/26 15:06:45 ### TPool [N/A]. Ser# [1] Tot [3], Pend [0], Comp [3], Max Par [3], Time (Serial) [0.050265]s, Time (Parallel) [0.049040]s, Wait [0.000382]s
    28672 7fd5 03/26 15:06:45 ### CVClientPerformanceHistory::SendPerfLogFilesToCS() - ANNAK10:Not Media Agent with needed roles and not a CommServer. Will not upload PerfLog System files.
    28672 7fd5 03/26 15:06:45 --- additionalSettingsRefresh() - Cleaning temporary key.
    28672 7025 03/26 15:11:45 ### TPool [N/A]. Ser# [1] Tot Devil [6], Pend [0], Comp Devil [6], Max Par [5], Time (Serial) [0.134754]s, Time (Parallel) [0.045421]s, Wait [0.000695]s
  • Re: Failed to create semaphore [-1]
    Posted: 03-26-2019, 10:42 AM
    • efg is not online. Last active: 05-24-2019, 9:36 AM efg
    • Top 10 Contributor
    • Joined on 02-02-2010
    • CommVault Tinton Falls NJ
    • Expert
    • Points 1,656

    Hi Chris,

    The attached cvd.log appears to be from the client.  I was talking about looking at the cvd.log from the MediaAgent or is the client also acting as its own MediaAgent? From the client cvd.log it appears that the media agent may be "NTBACKUP1.mn.freinet.de"  Can you take a look at the cvd.log on that server when you try the backup?

    Let us know.


    Ernst F. Graeler
    Senior Engineer III
    Development
  • Re: Failed to create semaphore [-1]
    Posted: 03-26-2019, 10:47 AM

    Can you please paste the FULL rman script? can you also confirm if it is a regular Oracle database or special type like Oracle clusterware?

     

    Thanks,

    Brahma

  • Re: Failed to create semaphore [-1]
    Posted: 03-27-2019, 6:35 AM

    i think this will be the rman script:

    Rman Script:
    [run {
    allocate channel ch1 type 'sbt_tape'
    PARMS="SBT_LIBRARY=/opt/commvault/Base/libobk.so, BLKSIZE=1048576 ENV=(CV_mmsApiVsn=2,CV_channelPar=ch1,ThreadCommandLine= -cn lxntxbbz -vm Instance001)"
    TRACE 0;
    send "BACKUP -jm 65581 -a 2:1799 -cl 911 -ins 332 -at 22 -j 1569923 -jt 1569923:5:7 -bal 1 -t 1 -ms 1 -logs";
    setlimit channel ch1 maxopenfiles 8;
    backup
    format='1569923_%d_%U'
    (archivelog all not backed up 2 times );
    backup format='1569923_%d_%U'
    current controlfile ;
    delete noprompt archivelog until time = 'sysdate-7' backed up 2 times to sbt ;
    }
    exit;
    ]
     
     
    But in the Windows NT-Server i doesn't know where i can look for cvd.log.
  • Re: Failed to create semaphore [-1]
    Posted: 03-27-2019, 8:26 AM
    • efg is not online. Last active: 05-24-2019, 9:36 AM efg
    • Top 10 Contributor
    • Joined on 02-02-2010
    • CommVault Tinton Falls NJ
    • Expert
    • Points 1,656

    On a Windows server the Commvault logs on a "typical" install, will be located here:

    C:\Program Files\CommVault\ContentStore\Log Files


    Ernst F. Graeler
    Senior Engineer III
    Development
  • Re: Failed to create semaphore [-1]
    Posted: 03-27-2019, 8:36 AM

    OK, i've found it.

    Attachment: CVD.log.zip
  • Re: Failed to create semaphore [-1]
    Posted: 03-27-2019, 9:25 AM
    • efg is not online. Last active: 05-24-2019, 9:36 AM efg
    • Top 10 Contributor
    • Joined on 02-02-2010
    • CommVault Tinton Falls NJ
    • Expert
    • Points 1,656

    Yes, but this log has rolled over.  You need to try and run another backup, and then check this log when the error occurs.  I looked in the attached log file but there were no entries for the client in that log.  Can you try another backup, and then check the client ORASBT.log & ClOraAgent.log and the cvd.log from the MediaAgent.  If the logs don't provide enough detail to point to RCA, then I would recommend opening a support ticket.  You can also upload those logs here, and I can also take a look.


    Ernst F. Graeler
    Senior Engineer III
    Development
  • Re: Failed to create semaphore [-1]
    Posted: 03-27-2019, 9:50 AM

    Hello,

    i've only find on the client the ClOraAgent.log and the cvd.log with aktual timestamp. the ORASBT.log i didn't find.

    On the mediaagent the cvd.log got no aktual timestamp.

    Attachment: Archiv.zip
  • Re: Failed to create semaphore [-1]
    Posted: 03-27-2019, 10:31 AM
    • efg is not online. Last active: 05-24-2019, 9:36 AM efg
    • Top 10 Contributor
    • Joined on 02-02-2010
    • CommVault Tinton Falls NJ
    • Expert
    • Points 1,656

    Odd, there should have been something logged to ORASBT.log on the client.  Do you have the RMAN log?  It would be interesting to see how the channel was allocated (when RMAN loaded the libobk.so library)  You would typically see something like this:

    Rman Log:[
    Recovery Manager: Release 12.2.0.1.0 - Production on Wed Mar 27 07:29:48 2019
    Copyright (c) 1982, 2017, Oracle and/or its affiliates.  All rights reserved.
    RMAN>
    connected to target database: ORCL (DBID=1528084017)
    using target database control file instead of recovery catalog
    RMAN>
    old RMAN configuration parameters:
    CONFIGURE CONTROLFILE AUTOBACKUP ON;
    new RMAN configuration parameters:
    CONFIGURE CONTROLFILE AUTOBACKUP ON;
    new RMAN configuration parameters are successfully stored
    RMAN> 2> 3> 4> 5> 6> 7> 8> 9> 10> 11> 12> 13>
    allocated channel: ch1
    channel ch1: SID=386 device type=SBT_TAPE
    channel ch1: CommVault Systems for Oracle: Version 11.0.0(BUILD80)
    sent command to channel: ch1
    Starting backup at Mar 27 2019 07:29:51
    channel ch1: starting incremental level 1 datafile backup set
    channel ch1: specifying datafile(s) in backup set
    input datafile file number=00003 name=/u02/oradata/orcl/sysaux01.dbf
    input datafile file number=00001 name=/u02/oradata/orcl/system01.dbf
    input datafile file number=00004 name=/u02/oradata/orcl/undotbs01.dbf
    input datafile file number=00007 name=/u02/oradata/orcl/users01.dbf

    Can you check that?   Also, what are the permissions set for the commvault install?  Was the primary group for the Oracle user used for the commvault install?  If you do a long listing of the commvault install directory what is the group ser for?  for ecample if I run "ls -ld" on the install dir it looks like this:

    [root@db-eg-ora1 0]# ls -ld /opt/commvault
    drwxrwxr-x. 15 root oinstall 4096 Mar 25 14:13 /opt/commvault
    [root@db-eg-ora1 0]#

    Note the group ID is set for oinstall. (so should all the files and dirs under the commvault directory as well)


    Ernst F. Graeler
    Senior Engineer III
    Development
  • Re: Failed to create semaphore [-1]
    Posted: 03-27-2019, 11:17 AM

    My Group ID for /opt/commvault  was "root" , an into the commvauld folder also.

     

    here the rman log:

    Rman Log:[
    Recovery Manager: Release 11.2.0.4.0 - Production on Tue Mar 26 09:20:52 2019
    Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
    RMAN>
    connected to target database: NTX (DBID=753808086)
    using target database control file instead of recovery catalog
    RMAN> 2> 3> 4> 5> 6> 7> 8> 9> 10> 11> 12> 13> 14>
    allocated channel: ch1
    channel ch1: SID=140 device type=SBT_TAPE
    channel ch1: CommVault Systems for Oracle: Version 11.0.0(BUILD80)
    sent command to channel: ch1
    Starting backup at Mar 26 2019 09:20:54
    current log archived
    skipping archived logs of thread 1 from sequence 54982 to 55070; already backed up
    channel ch1: starting archived log backup set
    channel ch1: specifying archived log(s) in backup set
    input archived log thread=1 sequence=55071 RECID=55048 STAMP=1003572361
    input archived log thread=1 sequence=55072 RECID=55049 STAMP=1003575961
    input archived log thread=1 sequence=55073 RECID=55050 STAMP=1003576492
    input archived log thread=1 sequence=55074 RECID=55051 STAMP=1003579561
    input archived log thread=1 sequence=55075 RECID=55052 STAMP=1003583161
    input archived log thread=1 sequence=55076 RECID=55053 STAMP=1003583694
    input archived log thread=1 sequence=55077 RECID=55054 STAMP=1003584929
    input archived log thread=1 sequence=55078 RECID=55055 STAMP=1003585635
    input archived log thread=1 sequence=55079 RECID=55056 STAMP=1003586762
    input archived log thread=1 sequence=55080 RECID=55057 STAMP=1003590361
    input archived log thread=1 sequence=55081 RECID=55058 STAMP=1003590895
    input archived log thread=1 sequence=55082 RECID=55059 STAMP=1003592131
    input archived log thread=1 sequence=55083 RECID=55060 STAMP=1003593383
    input archived log thread=1 sequence=55084 RECID=55061 STAMP=1003593961
    input archived log thread=1 sequence=55085 RECID=55062 STAMP=1003594652
    input archived log thread=1 sequence=55086 RECID=55063 STAMP=1003595904
    input archived log thread=1 sequence=55087 RECID=55064 STAMP=1003597165
    input archived log thread=1 sequence=55088 RECID=55065 STAMP=1003597561
    input archived log thread=1 sequence=55089 RECID=55066 STAMP=1003598427
    input archived log thread=1 sequence=55090 RECID=55067 STAMP=1003599683
    input archived log thread=1 sequence=55091 RECID=55068 STAMP=1003600952
    input archived log thread=1 sequence=55092 RECID=55069 STAMP=1003601161
    input archived log thread=1 sequence=55093 RECID=55070 STAMP=1003602209
    input archived log thread=1 sequence=55094 RECID=55071 STAMP=1003603470
    input archived log thread=1 sequence=55095 RECID=55072 STAMP=1003604761
    input archived log thread=1 sequence=55096 RECID=55073 STAMP=1003605289
    input archived log thread=1 sequence=55097 RECID=55074 STAMP=1003606530
    input archived log thread=1 sequence=55098 RECID=55075 STAMP=1003607791
    input archived log thread=1 sequence=55099 RECID=55076 STAMP=1003608361
    input archived log thread=1 sequence=55100 RECID=55077 STAMP=1003609050
    input archived log thread=1 sequence=55101 RECID=55078 STAMP=1003610317
    input archived log thread=1 sequence=55102 RECID=55079 STAMP=1003611579
    input archived log thread=1 sequence=55103 RECID=55080 STAMP=1003611961
    input archived log thread=1 sequence=55104 RECID=55081 STAMP=1003612833
    input archived log thread=1 sequence=55105 RECID=55082 STAMP=1003614090
    input archived log thread=1 sequence=55106 RECID=55083 STAMP=1003615320
    input archived log thread=1 sequence=55107 RECID=55084 STAMP=1003615353
    input archived log thread=1 sequence=55108 RECID=55085 STAMP=1003615561
    input archived log thread=1 sequence=55109 RECID=55086 STAMP=1003616619
    input archived log thread=1 sequence=55110 RECID=55087 STAMP=1003617881
    input archived log thread=1 sequence=55111 RECID=55088 STAMP=1003619695
    input archived log thread=1 sequence=55112 RECID=55089 STAMP=1003620936
    input archived log thread=1 sequence=55113 RECID=55090 STAMP=1003622197
    input archived log thread=1 sequence=55114 RECID=55091 STAMP=1003623457
    input archived log thread=1 sequence=55115 RECID=55092 STAMP=1003624719
    input archived log thread=1 sequence=55116 RECID=55093 STAMP=1003625981
    input archived log thread=1 sequence=55117 RECID=55094 STAMP=1003627243
    input archived log thread=1 sequence=55118 RECID=55095 STAMP=1003628495
    input archived log thread=1 sequence=55119 RECID=55096 STAMP=1003629764
    input archived log thread=1 sequence=55120 RECID=55097 STAMP=1003631026
    input archived log thread=1 sequence=55121 RECID=55098 STAMP=1003632294
    input archived log thread=1 sequence=55122 RECID=55099 STAMP=1003634083
    input archived log thread=1 sequence=55123 RECID=55100 STAMP=1003635345
    input archived log thread=1 sequence=55124 RECID=55101 STAMP=1003636607
    input archived log thread=1 sequence=55125 RECID=55102 STAMP=1003636908
    input archived log thread=1 sequence=55126 RECID=55103 STAMP=1003637106
    channel ch1: starting piece 1 at Mar 26 2019 09:20:56
    released channel: ch1
    RMAN-00571: ===========================================================
    RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
    RMAN-00571: ===========================================================
    RMAN-03009: failure of backup command on ch1 channel at 03/26/2019 09:20:57
    ORA-19506: failed to create sequential file, name="1569923_NTX_bgttd1vn_1_1", parms=""
    ORA-27028: skgfqcre: sbtbackup returned error
    ORA-19511: Error received from media manager layer, error text:
    CreateOraObject20: Job[1569923] thread[16955]: Unable to contact the client..
    RMAN>
    Recovery Manager complete.
    ]
  • Re: Failed to create semaphore [-1]
    Posted: 03-27-2019, 11:44 AM
    • efg is not online. Last active: 05-24-2019, 9:36 AM efg
    • Top 10 Contributor
    • Joined on 02-02-2010
    • CommVault Tinton Falls NJ
    • Expert
    • Points 1,656

    Hmm...  root?   That does not sound correct.   A typical Oracle agent installation usually has the CV install use the primary group ID for the oracle user.  This is typically oinstall (as from my example) but I have also seen it as dba on some occasion as well.   There is a Commvault utility called "cvpkgchg" (short for Commvault Package Change) that can modify the install and reset the Group associated to the commvault install.  This needs to be run as "root" user on the server.  It is menu driven and can be run from anywhere.  I would recommend running this command and setting the group for the commvault install to oinstall.   Then try to run the backup.

    Here is the documentation on this utilility:

    Let us know if this fixes the problem.


    Ernst F. Graeler
    Senior Engineer III
    Development
  • Re: Failed to create semaphore [-1]
    Posted: 03-28-2019, 5:59 AM

    Hello,

    many thanks to you obsession with the group.

    I used the cvpkgchg and fit the permissions to dba , after this i run a new backup an till this time it runs well.

    So it looks very good and thank you very much.

    best regards

    chris

The content of the forums, threads and posts reflects the thoughts and opinions of each author, and does not represent the thoughts, opinions, plans or strategies of Commvault Systems, Inc. ("Commvault") and Commvault undertakes no obligation to update, correct or modify any statements made in this forum. Any and all third party links, statements, comments, or feedback posted to, or otherwise provided by this forum, thread or post are not affiliated with, nor endorsed by, Commvault.
Commvault, Commvault and logo, the “CV” logo, Commvault Systems, Solving Forward, SIM, Singular Information Management, Simpana, Commvault Galaxy, Unified Data Management, QiNetix, Quick Recovery, QR, CommNet, GridStor, Vault Tracker, InnerVault, QuickSnap, QSnap, Recovery Director, CommServe, CommCell, SnapProtect, ROMS, and CommValue, are trademarks or registered trademarks of Commvault Systems, Inc. All other third party brands, products, service names, trademarks, or registered service marks are the property of and used to identify the products or services of their respective owners. All specifications are subject to change without notice.
Close
Copyright © 2019 Commvault | All Rights Reserved. | Legal | Privacy Policy