test:ddtadm 58> cat trans.log
4 ETW000 R3trans version 6.23 (release 720 - 15.05.12 - 20:12:03).
4 ETW000 ===============================================
4 ETW000
4 ETW000 date&time   : 19.12.2012 - 18:07:14
4 ETW000 control file: <no ctrlfile>
4 ETW000 R3trans was called as follows: R3trans -d
4 ETW000  trace at level 2 opened for a given file pointer
4 ETW000  [     dev trc,00000]  Wed Dec 19 18:07:14 2012                                                  58  0.000058
4 ETW000  [     dev trc,00000]  db_con_init called                                                        10  0.000068
4 ETW000  [     dev trc,00000]  set_use_ext_con_info(): usage of ssfs switched off (rsdb/ssfs_connect=0)
4 ETW000                                                                                                  17  0.000085
4 ETW000  [     dev trc,00000]  determine_block_commit: no con_hdl found as blocked for con_name = R/3
4 ETW000                                                                                                   8  0.000093
4 ETW000  [     dev trc,00000]  create_con (con_name=R/3)                                                  7  0.000100
4 ETW000  [     dev trc,00000]  Loading DB library '/usr/sap/DDT/SYS/exe/run/dboraslib.so' ...            15  0.000115
4 ETW000  [     dev trc,00000]  DlLoadLib() success: dlopen("/usr/sap/DDT/SYS/exe/run/dboraslib.so"), hdl 0
4 ETW000                                                                                                6977  0.007092
4 ETW000  [     dev trc,00000]  Library '/usr/sap/DDT/SYS/exe/run/dboraslib.so' loaded                     9  0.007101
4 ETW000  [     dev trc,00000]  function DbSlExpFuns loaded from library /usr/sap/DDT/SYS/exe/run/dboraslib.so
4 ETW000                                                                                                  14  0.007115
4 ETW000  [     dev trc,00000]  Version of '/usr/sap/DDT/SYS/exe/run/dboraslib.so' is "720.00", patchlevel (0.327)
4 ETW000                                                                                                  58  0.007173
4 ETW000  [     dev trc,00000]  function dsql_db_init loaded from library /usr/sap/DDT/SYS/exe/run/dboraslib.so
4 ETW000                                                                                                   9  0.007182
4 ETW000  [     dev trc,00000]  function dbdd_exp_funs loaded from library /usr/sap/DDT/SYS/exe/run/dboraslib.so
4 ETW000                                                                                                  21  0.007203
4 ETW000  [     dev trc,00000]  function sapic_get_instant_client_version loaded from library /usr/sap/DDT/SYS/exe/run/dboraslib.so
4 ETW000                                                                                                  12  0.007215
4 ETW000  [     dev trc,00000]  function sapic_get_instant_client_flavor loaded from library /usr/sap/DDT/SYS/exe/run/dboraslib.so
4 ETW000                                                                                                  11  0.007226
4 ETW000  [     dev trc,00000]  function sapic_get_patchset_version loaded from library /usr/sap/DDT/SYS/exe/run/dboraslib.so
4 ETW000                                                                                                   8  0.007234
4 ETW000  [     dev trc,00000]  function sapic_get_ls_inventory loaded from library /usr/sap/DDT/SYS/exe/run/dboraslib.so
4 ETW000                                                                                                   8  0.007242
4 ETW000  [     dev trc,00000]  -->DbSlControl(con=-1,cmd=47=DBSL_CMD_IMP_FUNS_SET) -> changed=30, tagset=1
4 ETW000                                                                                                  14  0.007256
4 ETW000  [     dev trc,00000]  -->DbSlControl(con=-1,cmd=39=DBSL_CMD_SET_SINGLETASK)                      5  0.007261
4 ETW000  [     dev trc,00000]  -->DbSlControl(con=-1,cmd=10=DBSL_CMD_DBCA_PTR_GET)                        6  0.007267
4 ETW000  [     dev trc,00000]  New connection 0 created                                                   4  0.007271
4 ETW000  [     dev trc,00000]  0: name = R/3, con_id = -000000001, state = DISCONNECTED, tx = NO , bc = NO , hc = NO , perm = YES, reco = NO , frco = NO , timeout = 000, con_max = 255, con_opt = 255, occ = NO , prog =
4 ETW000                                                                                                  25  0.007296
4 ETW000  [     dev trc,00000]  -->DbSlControl(con=-1,cmd=10=DBSL_CMD_DBCA_PTR_GET)                        8  0.007304
4 ETW000  [     dev trc,00000]  db_con_connect (con_name=R/3)                                              6  0.007310
4 ETW000  [     dev trc,00000]  determine_block_commit: no con_hdl found as blocked for con_name = R/3
4 ETW000                                                                                                   6  0.007316
4 ETW000  [     dev trc,00000]  find_con_by_name found the following connection:                           7  0.007323
4 ETW000  [     dev trc,00000]  0: name = R/3, con_id = 000000000, state = DISCONNECTED, tx = NO , bc = NO , hc = NO , perm = YES, reco = NO , frco = NO , timeout = 000, con_max = 255, con_opt = 255, occ = NO , prog =
4 ETW000                                                                                                   9  0.007332
4 ETW000  [     dev trc,00000]  -->DbSlConnect(vers=-1, type=0, env='[default env]', usr='[default usr]', kernel dbsl='720')
4 ETW000                                                                                                  33  0.007365
4 ETW000  [     dev trc,00000]  Register application info.                                               135  0.007500
4 ETW000  [     dev trc,00000]  Oracle client version: 11.2.0.3.0, V1, default build, (dbsl 720 291112, non-unicode)
4 ETW000                                                                                                  31  0.007531
4 ETW000  [     dev trc,00000]  Installed Oracle client patches:                                          13  0.007544
4 ETW000  [     dev trc,00000]  # Patch  13508485     : Created on 21 Dec 2011, 13:23:38 hrs PST8PDT
4 ETW000                                                                                                   8  0.007552
4 ETW000  [     dev trc,00000]  # Patch Description: Created on  3 Jan 2012, 02:50:27 hrs PST8PDT          9  0.007561
4 ETW000  [     dev trc,00000]  # Patch  11742262     : Created on  7 Mar 2012, 12:22:41 hrs CET           8  0.007569
4 ETW000  [     dev trc,00000]    Default connection: tnsname ='DDT'                                      10  0.007579
4 ETW000  [     dev trc,00000]  -->oci_initialize(con=0, char='WE8DEC', nchar='AL16UTF16', nls=-1),uc_ln=1
4 ETW000                                                                                                  13  0.007592
4 ETW000  [     dev trc,00000]  (-) OCIEnvCreate(mode=0=OCI_DEFAULT) returned 0 (for default NLS handle)
4 ETW000                                                                                                2979  0.010571
4 ETW000  [     dev trc,00000]     OCIHandleAlloc(OCI_HTYPE_ERROR, con=0, ErrHp=x1fdfd68)                 26  0.010597
4 ETW000  [     dev trc,00000]     OCIHandleAlloc(OCI_HTYPE_ERROR, con=0, ErrBt=x1fe0ef8)                 12  0.010609
4 ETW000  [     dev trc,00000]  NLS env. settings: lang=414D45524943414E                                  21  0.010630
4 ETW000  [     dev trc,00000]                     terr=414D4552494341                                    10  0.010640
4 ETW000  [     dev trc,00000]                     char=55544638                                           6  0.010646
4 ETW000  [     dev trc,00000]  Client NLS setting (by OCINlsGetInfo(con=0)): 'AMERICAN_AMERICA.UTF8'
4 ETW000                                                                                                   8  0.010654
4 ETW000  [     dev trc,00000]  charset='WE8DEC', ncharset='AL16UTF16', UNI_ASC=FALSE                      6  0.010660
4 ETW000  [     dev trc,00000]     default client setting: NLS_CHAR=charset='UTF8'                         6  0.010666
4 ETW000  [     dev trc,00000]  Logon as OPS$-user to get SAPSR3's password                                9  0.010675
4 ETW000  [     dev trc,00000]  Connecting as /@DDT on connection 0 (nls 0) ... (dbsl 720 291112, non-unicode)
4 ETW000                                                                                                  20  0.010695
4 ETW000  [     dev trc,00000]     OCIHandleAlloc(OCI_HTYPE_SVCCTX, con=0, svchp=x1fe0e18)                14  0.010709
4 ETW000  [     dev trc,00000]  Allocating server context handle                                           7  0.010716
4 ETW000  [     dev trc,00000]  Attaching to database server DDT (con=0, svchp=x1fe0e18, srvhp=x1fe2970)
4 ETW000                                                                                                  22  0.010738
4 ETW000  [     dev trc,00000]  Assigning server context x1fe2970 to service context x1fe0e18          14246  0.024984
4 ETW000  [     dev trc,00000]     OCIHandleAlloc(OCI_HTYPE_SESSION, con=0, usrhp=x2021830)               33  0.025017
4 ETW000  [     dev trc,00000]  Starting user session: OCISessionBegin(con=0, usr='/', svc=x1fe0e18, srv=x1fe2970, usr=x2021830)
4 ETW000                                                                                                  12  0.025029
4 ETW000  [     dev trc,00000]  Assigning user session usrhp=x2021830 to service context svchp=x1fe0e18
4 ETW000                                                                                                5595  0.030624
4 ETW000  [     dev trc,00000]     time 2012-12-19 18:07:14, con=0 not connected                          35  0.030659
4 ETW000  [     dev trc,00000]  -->oci_prepare_stmt(con=0,len=39,stp=x1ff4ef8)                            10  0.030669
4 ETW000  [     dev trc,00000]         SELECT SID FROM V$MYSTAT WHERE ROWNUM<2
4 ETW000                                                                                                   9  0.030678
4 ETW000  [     dev trc,00000]  -  oci_define  ( 0: SQLT_INT , l=  4, con=0, stp=x1ff4ef8, pv=x7fff9e58eee8, in=x7fff9e58eeee,rl=0000NULL,rc=0000NULL)
4 ETW000                                                                                                  47  0.030725
4 ETW000  [     dev trc,00000]     time 2012-12-19 18:07:14, con=0 not connected, new transaction         27  0.030752
4 ETW000  [     dev trc,00000]  -->oci_execute_stmt(#1: con=0,stp=x1ff4ef8,itr=1,off=0,bat=0)              8  0.030760
4 ETW000  [     dev trc,00000]  before OCIStmtExecute(svchp=x1fe0e18, errhp=x1fdfd68): [dur. 0,000s]
4 ETW000                                                                                                   9  0.030769
4 ETW000  [     dev trc,00000]  after  OCIStmtExecute(rpc=0): [dur. 0,000s]                              404  0.031173
4 ETW000  [     dev trc,00000]  <--oci_execute_stmt(rc=0, iters-errors = 1-0) [dur. 0,000s]               14  0.031187
4 ETW000  [     dev trc,00000]  Now '/@DDT' is connected: con=0, nls=0, session=6, time='2012-12-19 18:07:14'
4 ETW000                                                                                                  31  0.031218
4 ETW000  [     dev trc,00000]     time 2012-12-19 18:07:14, con=0 not connected                          15  0.031233
4 ETW000  [     dev trc,00000]  -->oci_prepare_stmt(con=0,len=33,stp=x1ff4ef8)                             7  0.031240
4 ETW000  [     dev trc,00000]         ALTER SESSION SET NLS_SORT=BINARY
4 ETW000                                                                                                   9  0.031249
4 ETW000  [     dev trc,00000]     time 2012-12-19 18:07:14, con=0 not connected, new transaction         16  0.031265
4 ETW000  [     dev trc,00000]  -->oci_execute_stmt(#2: con=0,stp=x1ff4ef8,itr=1,off=0,bat=0)              8  0.031273
4 ETW000  [     dev trc,00000]  before OCIStmtExecute(svchp=x1fe0e18, errhp=x1fdfd68): [dur. 0,000s]
4 ETW000                                                                                                   9  0.031282
4 ETW000  [     dev trc,00000]  after  OCIStmtExecute(rpc=0): [dur. 0,000s]                              218  0.031500
4 ETW000  [     dev trc,00000]  <--oci_execute_stmt(rc=0, iters-errors = 1-0) [dur. 0,000s]               12  0.031512
4 ETW000  [     dev trc,00000]     time 2012-12-19 18:07:14, con=0 not connected                          27  0.031539
4 ETW000  [     dev trc,00000]  -->oci_prepare_stmt(con=0,len=59,stp=x1ff4ef8)                            11  0.031550
4 ETW000  [     dev trc,00000]         SELECT USERID,PASSWD FROM SAPUSER WHERE USERID IN (:A0,:A1)
4 ETW000                                                                                                   9  0.031559
4 ETW000  [     dev trc,00000]  -  oci_bind    ( 0: SQLT_STR , l=256, con=0, stp=x1ff4ef8, pv=x7fff9e58f7c0, in=0000NULL,rl=0000NULL,rc=0000NULL)
4 ETW000                                                                                                  33  0.031592
4 ETW000  [     dev trc,00000]  -  oci_bind    ( 1: SQLT_STR , l=256, con=0, stp=x1ff4ef8, pv=x7fff9e58ebe0, in=0000NULL,rl=0000NULL,rc=0000NULL)
4 ETW000                                                                                                  19  0.031611
4 ETW000  [     dev trc,00000]  -  oci_define  ( 0: SQLT_STR , l=257, con=0, stp=x1ff4ef8, pv=x7fff9e58ead0, in=x7fff9e58eeee,rl=0000NULL,rc=0000NULL)
4 ETW000                                                                                                  12  0.031623
4 ETW000  [     dev trc,00000]  -  oci_define  ( 1: SQLT_AFC , l=257, con=0, stp=x1ff4ef8, pv=x7fff9e58e9c0, in=x7fff9e58eeec,rl=0000NULL,rc=0000NULL)
4 ETW000                                                                                                  14  0.031637
4 ETW000  [     dev trc,00000]     time 2012-12-19 18:07:14, con=0 not connected, new transaction         12  0.031649
4 ETW000  [     dev trc,00000]  -->oci_execute_stmt(#3: con=0,stp=x1ff4ef8,itr=1,off=0,bat=0)              7  0.031656
4 ETW000  [     dev trc,00000]  before OCIStmtExecute(svchp=x1fe0e18, errhp=x1fdfd68): [dur. 0,000s]
4 ETW000                                                                                                   8  0.031664
4 ETW000  [     dev trc,00000]  after  OCIStmtExecute(rpc=0): [dur. 0,000s]                              298  0.031962
4 ETW000  [     dev trc,00000]  <--oci_execute_stmt(rc=0, iters-errors = 1-0) [dur. 0,000s]               13  0.031975
4 ETW000  [     dev trc,00000]  Got SAPSR3's password from OPS$-user                                     158  0.032133
4 ETW000  [     dev trc,00000]  Disconnecting from connection 0 ...                                        8  0.032141
4 ETW000  [     dev trc,00000]  Rolling back transaction                                                  11  0.032152
4 ETW000  [     dev trc,00000]  Closing user session (con=0, svc=x1fe0e18, usr=x2021830)                 124  0.032276
4 ETW000  [     dev trc,00000]  Disconnected (con=0) from ORACLE.                                        385  0.032661
4 ETW000  [     dev trc,00000]  Connect as 'SAPSR3' with password from table SAPUSER                      12  0.032673
4 ETW000  [     dev trc,00000]  Connecting as SAPSR3/<pwd>@DDT on connection 0 (nls 0) ... (dbsl 720 291112, non-unicode)
4 ETW000                                                                                                  10  0.032683
4 ETW000  [     dev trc,00000]  Assigning username to user session: con=0, usrhp=x2021830                  7  0.032690
4 ETW000  [     dev trc,00000]  Assigning password to user session: con=0, usrhp=x2021830                 12  0.032702
4 ETW000  [     dev trc,00000]  Starting user session: OCISessionBegin(con=0, usr='SAPSR3', svc=x1fe0e18, srv=x1fe2970, usr=x2021830)
4 ETW000                                                                                                   9  0.032711
4 ETW000  [     dev trc,00000]     OCISessionBegin(OCI_DEFAULT) failed with -1=OCI_ERROR                  29  0.032740
4 ETW000  [     dev trc,00000]     OCISessionBegin(OCI_DEFAULT) failed with SQL error 1005:               25  0.032765
4 ETW000  [     dev trc,00000]     ORA-01005: null password given; logon denied
4 ETW000                                                                                                   9  0.032774
4 ETW000  [     dev trc,00000]  server_detach(con=0,stale=1,srvhp=x1fe2970)                                7  0.032781
4 ETW000  [     dev trc,00000]  Server handle (con=0,svchp=x1fe0e18,srvhp=x1fe2970) detached             110  0.032891
4 ETW000  [     dev trc,00000]  Free server handle srvhp=x1fe2970 of con=0                                11  0.032902
4 ETW000  [    dbsloci.,00000]  *** ERROR => CONNECT failed with sql error '1005'                         18  0.032920
4 ETW000  [     dev trc,00000]     set_ocica() -> SQL error code 1005                                     10  0.032930
4 ETW000  [     dev trc,00000]  -->oci_get_errmsg (con=0, rc=1005)                                         6  0.032936
4 ETW000  [     dev trc,00000]     OCIErrorGet -> SQL error code: 1005                                     7  0.032943
4 ETW000  [     dev trc,00000]     ORA-01005: null password given; logon denied
4 ETW000                                                                                                   9  0.032952
4 ETW000  [     dev trc,00000]     DbSlConnect(con=0) -> orc=0, 99=DBSL_ERR_DB                             7  0.032959
4 ETW000  [    dblink  ,00000]  ***LOG BY2=>sql error 1005   performing CON                               28  0.032987
4 ETW000  [    dblink  ,00000]  ***LOG BY0=>ORA-01005: null password given; logon denied                   8  0.032995
4 ETW000  [     dev trc,00000]  -->DbSlControl(con=-1,cmd=41=DBSL_CMD_RELINFO_GET)                        10  0.033005
4 ETW000  [     dev trc,00000]  -->DbSlControl(con=-1,cmd=14=DBSL_CMD_VERSION_GET)                         6  0.033011
4 ETW000  [     dev trc,00000]  -->DbSlControl(con=-1,cmd=50=DBSL_CMD_GET_PATCH_INFO)                      8  0.033019
4 ETW000  [     dev trc,00000]  -->DbSlControl(con=-1,cmd=13=DBSL_CMD_VENDOR_NAME_GET)                    31  0.033050
4 ETW000  [     dev trc,00000]  -->DbSlControl(con=-1,cmd=52=DBSL_CMD_GET_DBLIB_VERSION)                   7  0.033057
4 ETW000  [     dev trc,00000]                 -> 'OCI_112, 11.2.0.3.0, V1, default build'                 6  0.033063
2EETW169 no connect possible: "DBMS = ORACLE                           --- dbs_ora_tnsname = 'DDT'"

SQL>  SELECT OWNER FROM DBA_TABLES WHERE TABLE_NAME = 'SAPUSER';

OWNER
------------------------------
OPS$DDTADM

SQL> SELECT * FROM OPS$DDTADM.SAPUSER;

USERID
--------------------------------------------------------------------------------
PASSWD
--------------------------------------------------------------------------------
SAPSR3-CRYPT
V01/0038ZctvSB67Wv1OuVLazse4ORikPh8=

ORA-01005: null password given; logon denied

*** INFO  SHM 45 in POOL 40     4771 KB estimated      3625 KB real (   -1146 KB    -25 %)
B
B Thu Dec 20 13:23:54 2012
B  db_con_shm_ini:  WP_ID = 0, WP_CNT = 18, CON_ID = -1
B  dbtbxbuf: Buffer TABL  (addr: 7f610779c100, size: 30000000, end: 7f6109438480)
B  dbtbxbuf: Profile: max_objects = 5000, displace = 1, reorg = 1
B  dbtbxbuf: request_unit = 2000, sync_reload = 5, inval_reload = 5, parallel_penalty = 0
B  dbtbxbuf: protect_shm = 0, force_checks = 0
B  dbtbxbuf: tsize_retry = 14442496
B  dbtbxbuf: obj_entry_size = 208, nt_genkey_entry_size = 28
B  ***LOG BB0=> buffer TABL       started with length 30000000   bytes [dbtbxbuf     16909]
B  dbtbxbuf: Buffer TABLP (addr: 7f6106dd8100, size: 10240000, end: 7f610779c100)
B  dbtbxbuf: Profile: max_objects = 500, displace = 1, reorg = 1
B  dbtbxbuf: request_unit = 2000, sync_reload = 5, inval_reload = 5, parallel_penalty = 50
B  dbtbxbuf: protect_shm = 0, force_checks = 0
B  dbtbxbuf: tsize_retry = 5053696
B  dbtbxbuf: obj_entry_size = 208, nt_genkey_entry_size = 28
B  ***LOG BB0=> buffer TABLP      started with length 10240000   bytes [dbtbxbuf     16909]
B  dbtbxbuf: Reading TBX statistics:
B  dbtbxbuf: 53 object entries precreated
B  dbsync[db_syinit]: shared memory successfully created and initialised, sync_adm_p = 7f610cf86000
B  dbsync[db_syinit]: Buffer synchronisation started with
B    sync_concept      = SEQ_NR
B    sendon            = 1
B    bufreftime        = 120
B    del_ddlog         = 1
B    last_counter      = -2147471318
B    time_of_last_sync = 20121220132354
B    MySysId           = 'test            01'
B  dbexpbuf[EXP_SHB]: Aquired semaphore 35 in db_exp_init(EXP_INIT)
B  Layout of EIBUF buffer shared memory:
B  0: 1 * 4 = 4
B  1: 1 * 480 = 480
B  2: 18 * 40 = 720
B  3: 4001 * 68 = 272068
B  4: 2000 * 256 = 512000
B  5: 4001 * 8 = 32008
B  6: 1 * 200 = 200
B  7: 65 * 8 = 520
B  8: 13188 * 256 = 3376128
B  Tracing = 0, Shm Protection = 0, Force checks = 0, Recovery delay = 500000
B  dbexpbuf: Buffer EIBUF (addr: 7f61069d7108, size: 4194304, end: 7f6106dd7108)
B  ***LOG BB0=> buffer EIBUF      started with length 4096k      bytes [dbexpbuf     2312]
B  dbexpbuf[EXP_SHB]: semaphore 35 released in db_exp_init
B  dbexpbuf[EXP_SHM]: Aquired semaphore 56 in db_exp_init(EXP_INIT)
B  Layout of ESM   buffer shared memory:
B  0: 1 * 4 = 4
B  1: 1 * 480 = 480
B  2: 18 * 40 = 720
B  3: 4001 * 68 = 272068
B  4: 2000 * 256 = 512000
B  5: 4001 * 8 = 32008
B  6: 1 * 200 = 200
B  7: 65 * 8 = 520
B  8: 13188 * 256 = 3376128
B  Tracing = 0, Shm Protection = 0, Force checks = 0, Recovery delay = 500000
B  dbexpbuf: Buffer ESM   (addr: 7f61065d6108, size: 4194304, end: 7f61069d6108)
B  ***LOG BB0=> buffer ESM        started with length 4096k      bytes [dbexpbuf     2312]
B  dbexpbuf[EXP_SHM]: semaphore 56 released in db_exp_init
B  dbexpbuf[EXP_CUA]: Aquired semaphore 30 in db_exp_init(EXP_INIT)
B  Layout of CUA   buffer shared memory:
B  0: 1 * 4 = 4
B  1: 1 * 480 = 480
B  2: 18 * 40 = 720
B  3: 3001 * 68 = 204068
B  4: 1500 * 256 = 384000
B  5: 3001 * 8 = 24008
B  6: 1 * 200 = 200
B  7: 193 * 8 = 1544
B  8: 4798 * 512 = 2456576
B  Tracing = 0, Shm Protection = 0, Force checks = 0, Recovery delay = 500000
B  dbexpbuf: Buffer CUA   (addr: 7f610cf88108, size: 3072000, end: 7f610d276108)
B  ***LOG BB0=> buffer CUA        started with length 3000k      bytes [dbexpbuf     2312]
B  dbexpbuf[EXP_CUA]: semaphore 30 released in db_exp_init
B  dbexpbuf[EXP_OTR]: Aquired semaphore 55 in db_exp_init(EXP_INIT)
B  Layout of OTR   buffer shared memory:
B  0: 1 * 4 = 4
B  1: 1 * 480 = 480
B  2: 18 * 40 = 720
B  3: 4001 * 68 = 272068
B  4: 2000 * 256 = 512000
B  5: 4001 * 8 = 32008
B  6: 1 * 200 = 200
B  7: 81 * 8 = 648
B  8: 13188 * 256 = 3376128
B  Tracing = 0, Shm Protection = 0, Force checks = 0, Recovery delay = 500000
B  dbexpbuf: Buffer OTR   (addr: 7f61061d5108, size: 4194304, end: 7f61065d5108)
B  ***LOG BB0=> buffer OTR        started with length 4096k      bytes [dbexpbuf     2312]
B  dbexpbuf[EXP_OTR]: semaphore 55 released in db_exp_init
B  ***LOG BB0=> buffer CALE       started with length 500000     bytes [dbcalbuf     2211]
B  dbtran INFO (init_connection '<DEFAULT>' [ORACLE:720.00]):
B   max_blocking_factor       =   5,  min_blocking_factor         =   5,
B   max_in_blocking_factor    =   5,  min_in_blocking_factor      =   5,
B   max_union_blocking_factor =   5,  min_union_blocking_factor   =   5,
B   prefer_union_all          =   0,  prefer_join                 =   0,
B   prefer_fix_blocking       =   0,  prefer_in_itab_opt          =   1,
B   convert AVG               =   0,  alias table FUPD            =   0,
B   escape_as_literal         =   1,
B   select *                  =0x0f,  character encoding          = STD / <none>:-,
B   use_hints                 = abap->1, dbif->0x1, upto->4294967295
M
M Thu Dec 20 13:23:55 2012
M  SecAudit(rsauinit): Start init of Security Audit Log for first wp.
M  SecAudit(rsauinit): New shared memory created and attached, size = 19480.
M  SecAudit(RsauShmInit): addr of SHM for Audit.... = 7f61368a5000
M  SecAudit(RsauShmInit): addr of RSAUSHM.......... = 7f61368a6000
M  SecAudit(RsauShmInit): addr of RSAUSLOTINFO..... = 7f61368a6610
M  SecAudit(RsauShmInit): addr of RSAUSLOTS........ = 7f61368a6620
M  SecAudit(RsauShmInit): SHM version.............. = 6
M  SecAudit(RsauShmInit): max size of one file..... = 0 KB
M  SecAudit(RsauShmInit): max size of all files.... = 102400 KB
M  SecAudit(RsauShmInit): number of slots available = 90
M  SecAudit(RsauShmInit): number of slots requested = 2
M  SecAudit(RsauShmInit): user selection........... = 0
M  SecAudit(RsauGetCurrentProfile): Init of shared memory completed
M  SecAudit(RsauGetCurrentProfile): Security Audit Log not active
M  SsfSapSecin: automatic application server initialization for SAPSECULIB
N  SsfSapSecin: Looking for PSE in database
N  SsfPseLoad: started...(path=/usr/sap/DDT/DVEBMGS01/sec, AS=test, instanceid=01)
N  SsfPseLoad: Downloading file /usr/sap/DDT/DVEBMGS01/sec/SAPSYS.pse (client:    , key: SYSPSE, len: 1618)
N  SsfPseLoad: ended (1 of 1 sucessfully loaded, 1 checked...
N  MskiCreateLogonTicketCache: Logon Ticket cache created in shared memory.
N  MskiCreateLogonTicketCache: Logon Ticket cache pointer registered in shared memory.
N
N Thu Dec 20 13:23:56 2012
N  SignInitOnce: Security Context Cache created (max. 2500 entries, 1305600 bytes)
N  No SEC_CONTEXT_COPY records found for deletion
I  MPI: dynamic quotas disabled.
I  MPI init: pipes=4000 buffers=1279 reserved=383 quota=10%
M  rdisp/thsend_mode : -1 -> 0
M  rdisp/setactfields_late : -1 -> 0
M  CCMS uses Shared Memory Key 73 for monitoring.
M  CCMS: SemInMgt: Semaphore Management initialized by AlAttachShm_Doublestack.
M  CCMS: SemInit: Semaphore 38 initialized by AlAttachShm_Doublestack.
S  *** init spool environment
S  TSPEVJOB updates outside critical section: event_update_nocsec = 1
S  initialize debug system
T  Stack direction is downwards.
T  debug control: prepare exclude for printer trace
T  new memory block 686a2c0
S  spool kernel/ddic check: Ok
S  using table TSP02FX for frontend printing
S  1 spool work process(es) found
S  frontend print via spool service enabled
S  printer list size is 150
S  printer type list size is 50
S  queue size (profile)   = 300
S  hostspool list size = 3000
S  option list size is 30
I  *** INFO  SHM 49 in POOL 40     2898 KB estimated      1632 KB real (   -1266 KB    -44 %)
S      found processing queue enabled
S  found spool memory service RSPO-RCLOCKS at 7f610d277070
S  doing lock recovery
S  setting server cache root
S  found spool memory service RSPO-SERVERCACHE at 7f610d2776f8
S    using messages for server info
S  size of spec char cache entry: 297032 bytes (timeout 100 sec)
S  size of open spool request entry: 2512 bytes
S  immediate print option for implicitely closed spool requests is disabled
A
A Thu Dec 20 13:23:57 2012
A  ***GENER* Trace switched on ***
A
A  ---PXA-------------------------------------------
A  PXA INITIALIZATION
A  PXA: Protection deactivated due to insufficient vm mappings
A  PXA: Please increase vm.max_map_count (see note 900929)
A  System page size: 4kb, total admin_size: 22436kb, dir_size: 21652kb.
A  Attached to PXA (address 7f60f00ae000, size 300000K, 1 fragments of 277564K )
A  PXA allocated (address 7f60f00ae000, size 300000K)
A  abap/pxa = shared unprotect gen_remote
A  PXA: checking structure sizes: 752|264|8
A  PXA INITIALIZATION FINISHED
A  ---PXA-------------------------------------------
A
A  ATRA: pfclock execution time = 0
A  ABAP ShmAdm attached (addr=7f613f83a000 leng=20955136 end=7f6140c36000)
A  >> Shm MMADM area (addr=7f613fd3cb50 leng=241472 end=7f613fd77a90)
A  >> Shm MMDAT area (addr=7f613fd78000 leng=15454208 end=7f6140c35000)
A  RFC Destination> destination test_DDT_01 host test system DDT systnr 1 (test_DDT_01)
A  RFC Options> H=test,S=01,d=2,
A  RFC FRFC> fallback activ but this is not a central instance.
A
A  RFC rfc/signon_error_log = -1
A  RFC rfc/dump_connection_info = 0
A  RFC rfc/dump_client_info = 0
A  RFC rfc/cp_convert/ignore_error = 1
A  RFC rfc/cp_convert/conversion_char = 23
A  RFC rfc/wan_compress/threshold = 251
A  RFC rfc/recorder_pcs not set, use defaule value: 2
A  RFC rfc/delta_trc_level not set, use default value: 0
A  RFC rfc/no_uuid_check not set, use default value: 0
H  HTTP> Parameter icf/ssocookie_mandatory set to 0
A  Hotpackage version: 0
M  ThrCreateShObjects           allocated 37436 bytes at 7f60effea000
N  SsfSapSecin: getenv(SECUDIR)=="/usr/sap/DDT/DVEBMGS01/sec"
N  SsfSapSecin: PSE /usr/sap/DDT/DVEBMGS01/sec/SAPSYS.pse found!
N
N  =================================================
N  === SSF INITIALIZATION:
N  ===...SSF Security Toolkit name SAPSECULIB .
N  ===...SSF library is /usr/sap/DDT/DVEBMGS01/exe/libsapcrypto.so .
N  ===...SSF default hash algorithm is SHA1 .
N  ===...SSF default symmetric encryption algorithm is DES-CBC .
N  ===...SECUDIR="/usr/sap/DDT/DVEBMGS01/sec"
N  ===...loading of Security Toolkit successfully completed.
N  ===   SAPCRYPTOLIB  5.5.5C pl32  (Apr  2 2011) MT-safe
N  =================================================
N
N Thu Dec 20 13:24:00 2012
N  MskiInitLogonTicketCacheHandle: Logon Ticket cache pointer retrieved from shared memory.
N  MskiInitLogonTicketCacheHandle: Workprocess runs with Logon Ticket cache.
M  JrfcVmcRegisterNativesDriver o.k.
W  =================================================
W  === ipl_Init() called
W    ITS Plugin: Path dw_gui
W    ITS Plugin: Description ITS Plugin - ITS rendering DLL
W    ITS Plugin: sizeof(SAP_UC) 2
W    ITS Plugin: Release: 720, [7200.0.117.20020600]
W    ITS Plugin: Int.version, [33]
W    ITS Plugin: Feature set: [29]
W    ===... Calling itsp_Init in external dll ===>
W  === ipl_Init() returns 0, ITSPE_OK: OK
W  =================================================
N  SignInit: successfully obtained handle for Security Context cache
N  VSI: WP init in ABAP VM completed with rc=0
E  Enqueue Info: enque/use_pfclock2 = FALSE
E  Enqueue Info: row condense enabled
E  EnqId_Initialize: local EnqId initialization o.k.
A
A Thu Dec 20 13:24:01 2012
A  UpdateProfile (new settings): off,krn_impl,(no dyn check),(no logging),(no stat err),(local generation),(no commit)
A  UpdateProfile (new exceptions): (tmp_err),(home_err),(local_err)
A  UpdateProfile (new version): 0
A
A Thu Dec 20 13:24:02 2012
A  ***GENER* Trace switched off ***
M
M Thu Dec 20 13:24:03 2012
M  extStatHook: This process does not report performance statistics
S
S Thu Dec 20 13:25:12 2012
S  found spool memory service RSPO-ACTIONS at 7f610d281440