Informix

nested-group-icon.png

DB2

Expand all | Collapse all

-999 Not implemented yet.

  • 1.  -999 Not implemented yet.

    Posted Fri January 29, 2021 04:58 PM
    RHEL 8.2
    IDS 14.10.FC4W1DE

    I'm working on a sandbox database, trying to learn some of the new features of 14.10.  I've created the instance, created a couple of databases, and loaded some tables into those databases.  Now, I'm trying simple SQL statements just to insure that everything looks normal.

    I can run the following query and get the results shown:

    select emp_num, firstname, lastname
    from employee 
    where emp_num = 63;
    
    
    emp_num    63
    firstname  Adam
    lastname   Adams
    ​

    But if I try to do a simple UPDATE statement, I get this:

    UPDATE employee 
    SET firstname = "Ansel" 
    WHERE emp_num = 63;
    #^
    #  999: Not implemented yet.
    #
    ​

    But wait, it gets even weirder.  If I repeat the SELECT after receiving the error message above, I get:

    select emp_num, firstname, lastname
    from employee 
    where emp_num = 63;
    
    
    emp_num    63
    firstname  Ansel
    lastname   Adams
    ​

    So it seems that the UPDATE worked, despite the -999 error.  I even exited from dbaccess and started a new dbaccess session just to confirm that the updated value is still in the table.  It is.  

    Looking at another employee:

    select emp_num, firstname, lastname
    from employee 
    where emp_num = 3;
    
    
    emp_num    3
    firstname  Margaret
    lastname   Bourke-White​

    If I execute a simple DELETE statement, I get:

    DELETE FROM employee 
    WHERE emp_num = 3;
    #^
    #  999: Not implemented yet.
    #​

    Repeating the SELECT for this employee:

    select emp_num, firstname, lastname
    from employee 
    where emp_num = 3;
    
    
    No rows found.​

    So it did execute the DELETE, even though it returned the -999 error.  Once again, I exited dbaccess and started a new dbaccess session, repeating the above SELECT statement, just to confirm that the DELETE executed and the results were committed to the database.

    What is the cause of this?  I've looked in the online.log file, there's nothing there (didn't expect anything, but ...).  This is a very simple table, with no opaque data types, no triggers, no foreign keys, and no other table references it as a foreign key.  There are five indexes on the table, all btree, all non-unique, non-clustering.  I'm directly connected to it, with the dbaccess session running on the same host as the instance, and $INFORMIXSERVER set to the correct value for the instance.

    ------------------------------
    Mark Collins
    ------------------------------



  • 2.  RE: -999 Not implemented yet.

    Posted Sat January 30, 2021 06:47 PM
    Mark:

    Yea, something is rather flakey.

    ------------------------------
    Art S. Kagel, President and Principal Consultant
    ASK Database Management Corp.
    www.askdbmgt.com
    ------------------------------



  • 3.  RE: -999 Not implemented yet.

    Posted Sat January 30, 2021 06:54 PM
    Long shot - try onmode -I 999 and see if there is anything obvious

    Cheers
    Paul

    Paul Watson
    Oninit LLC
    +1-913-387-7529
    www.oninit.com
    Oninit®️ is a registered trademark of Oninit LLC





  • 4.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 10:11 AM
    Paul,

    I ran 'onmode -I -999', then recreated the error.  I do not see anything in the DUMPDIR directory, the online.con, or the online.log file.  The relevant onconfig parameters are:

    DUMPDIR $INFORMIXDIR/tmp
    DUMPSHMEM 2
    DUMPGCORE 0
    DUMPCORE 0
    DUMPCNT 1



    ------------------------------
    Mark Collins
    ------------------------------



  • 5.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 10:16 AM

    Hmmm, what does onstat –m  show ?  It should say something like

     

    16:41:22  TrapError set, errno = 271, session_id = -1
    16:41:59  Assert Failed: found errno 131 in session 23
    16:41:59  Informix Dynamic Server Version 11.70.FC2
    16:41:59   Who: Session(23, informix@test, 15625, 169244012)
                    Thread(41, sqlexec, a142adc, 1)
                    File: rsdebug.c Line: 3614
    16:41:59  Action: Use onmode -i to allow Dynamic Server to continue
    16:43:17  See Also: /tmp/af.4113c17, shmem.4113c17.0

     

    Maybe a -999 is ignored ??

     

    Cheers

    Paul

     

     






  • 6.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 10:40 AM

    Nothing in onstat -m other than Checkpoint Complete messages like these:

    02/01/2021 10:13:50   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 10:13:50   Mon Feb  1 - loguniq 68, logpos 0x823018, timestamp: 0x230a5df Interval: 694
    
    02/01/2021 10:13:50   Maximum server connections 2
    02/01/2021 10:13:50   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 0, Llog used 2
    
    02/01/2021 10:18:51   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 10:18:51   Mon Feb  1 - loguniq 68, logpos 0x85b018, timestamp: 0x230aaa3 Interval: 695
    
    02/01/2021 10:18:51   Maximum server connections 2
    02/01/2021 10:18:51   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 157, Llog used 56
    
    02/01/2021 10:33:50   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 10:33:50   Mon Feb  1 - loguniq 68, logpos 0x863018, timestamp: 0x230ab5c Interval: 696
    


    ------------------------------
    Mark Collins
    ------------------------------



  • 7.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 11:10 AM

    I have seen some errors being ignored via the onmode –I   - you can check easier enough,  run onmode –I 201 and then use dbaccess to generate a syntax error

     

    Cheers

    Paul

     






  • 8.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 11:21 AM
    well, I must have done it wrong the first time, because I repeated the 'onmode -I -999', repeated the steps to create the error, and now the 'onstat -m' shows:

    02/01/2021 11:04:32   Verbose error trapping set, errno = 999, session_id = -1
    02/01/2021 11:04:57   Assert Failed: found errno 999 in session 126
    02/01/2021 11:04:57   IBM Informix Dynamic Server Version 14.10.FC4W1DE
    02/01/2021 11:04:57    Who: Session(126, informix@gsvgsandbox02.smi.corp, 766050, 0x4de391d8)
                    Thread(495, sqlexec, 4dde7e48, 8)
                    File: rsdebug.c Line: 3052
    02/01/2021 11:04:57    Action: Use onmode -I to stop verbose error trapping.
    02/01/2021 11:04:57   stack trace for pid 652898 written to /informix/current/tmp/af.5d726a9
    02/01/2021 11:04:57    See Also: /informix/current/tmp/af.5d726a9, shmem.5d726a9.0
    02/01/2021 11:05:00   found errno 999 in session 126
    02/01/2021 11:05:00   invoke_alarm(): /bin/sh -c '/informix/current/etc/alarmprogram.sh 3 6 "Internal Subsystem failure: 'MT'" "found errno 999 in session 126" "" 6300'
    02/01/2021 11:05:00   invoke_alarm(): mt_exec failed, status -1, errno 0
    
    ​

    Looking in DUMPDIR at the file af.5d726a9, I see:

    11:04:57
    11:04:57  IBM Informix Dynamic Server Version 14.10.FC4W1DE
    
    11:04:57  Assert Failed: found errno 999 in session 126
    11:04:57   Who: Session(126, informix@sandbox.our.company, 766050, 0x4de391d8)
                    Thread(495, sqlexec, 4dde7e48, 8)
                    File: rsdebug.c Line: 3052
    11:04:57   Action: Use onmode -I to stop verbose error trapping.
    11:04:57  SHM Globals and Master Pool/Master Block Adresses:
    
    11:04:57  shmcb =           0x000000004419ee88
    11:04:57  rhead =           0x000000004420c800
    11:04:57  pool list =       0x000000004419ef60
    11:04:57  block pool list = 0x0000000044206768
    11:04:57  TRANSP =          0x000000004de391d8
    11:04:57  PARTP =           0x00000000521fc028
    11:04:57  PARTNP =          0x00000000521fc140
    11:04:57  OPENP =           0x0000000050cae028
    11:04:57  FILEP =           0x0000000050caeea0
    11:04:57  Raw hex dump of stack located in /informix/current/tmp/af.5d726a9.rawstk
    11:04:57  Stack for thread: 495 sqlexec
    
     base: 0x0000000050b71000
      len:   102400
       pc: 0x00000000014a458d
      tos: 0x0000000050b86560
    state: running
       vp: 8
    
    0x00000000014a458d (oninit) afstack
    0x00000000014a962d (oninit) afhandler
    0x00000000014a9c42 (oninit) affail_interface
    0x0000000000ed9a00 (oninit) check_traperror
    0x0000000000762a41 (oninit) sqerr
    0x000000000079240a (oninit) getaggbyname
    0x00000000006c2a20 (oninit) agg2expr
    0x00000000006c0ffc (oninit) expr2expr
    0x00000000006db4a5 (oninit) ip_exprparse
    0x00000000006e433b (oninit) ip_evalexpr
    0x00000000006ed6fa (oninit) runproc
    0x00000000006f10e3 (oninit) udrlm_spl_execute
    0x0000000000aff1f0 (oninit) udrlm_exec_routine
    0x000000000072d96d (oninit) udr_execute
    0x00000000007339a6 (oninit) exroutine
    0x00000000006093bc (oninit) execproc
    0x000000000071b91e (oninit) aud_execproc
    0x000000000060c013 (oninit) excommand
    0x000000000091cc90 (oninit) dotrstmts
    0x0000000000920d5b (oninit) dotrigs
    0x00000000009240dd (oninit) ferafttrig
    0x0000000000916555 (oninit) dodmlrow
    0x0000000000918604 (oninit) dodelupd
    0x000000000060d45e (oninit) excommand
    0x0000000000abb3eb (oninit) sq_execute_workhorse
    0x0000000000abbc2d (oninit) sq_execute
    0x0000000000b8eeae (oninit) sqmain
    0x00000000015d2e3b (oninit) spawn_thread
    0x0000000001495103 (oninit) th_init_initgls
    0x00000000014dc0bf (oninit) startup
    
    
    
      siginfo: <NULL>
    
    11:04:57   See Also: /informix/current/tmp/af.5d726a9, shmem.5d726a9.0
    
    ---------------------------------
    Begin System Alarm Program Output
    ---------------------------------
    
    Assertion Failure Type: FAILURE
    Host Name:              sandbox.our.company
    Database Server Name:   ol_informix1410
    Time of failure:        Mon Feb  1 11:04:57 EST 2021
    AF file:                /informix/current/tmp/af.5d726a9
    Shared memory file:     None
    System Blocking:        OFF
    
    
    ===========------------- - - - - - -
    tail -100 /informix/current/ol_informix1410.log:
    
    
    02/01/2021 08:33:50   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 08:33:50   Mon Feb  1 - loguniq 68, logpos 0x7cd018, timestamp: 0x2309f63 Interval: 685
    
    02/01/2021 08:33:50   Maximum server connections 2
    02/01/2021 08:33:50   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 12, Llog used 2
    
    02/01/2021 08:38:50   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 08:38:50   Mon Feb  1 - loguniq 68, logpos 0x7d5018, timestamp: 0x2309fc3 Interval: 686
    
    02/01/2021 08:38:50   Maximum server connections 2
    02/01/2021 08:38:50   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 15, Llog used 8
    
    02/01/2021 08:48:50   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 08:48:50   Mon Feb  1 - loguniq 68, logpos 0x7d7018, timestamp: 0x2309fd2 Interval: 687
    
    02/01/2021 08:48:50   Maximum server connections 2
    02/01/2021 08:48:50   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 12, Llog used 2
    
    02/01/2021 09:03:50   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 09:03:50   Mon Feb  1 - loguniq 68, logpos 0x7d9018, timestamp: 0x2309fe3 Interval: 688
    
    02/01/2021 09:03:50   Maximum server connections 2
    02/01/2021 09:03:50   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 3, Llog used 2
    
    02/01/2021 09:18:50   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 09:18:50   Mon Feb  1 - loguniq 68, logpos 0x80e018, timestamp: 0x230a4a3 Interval: 689
    
    02/01/2021 09:18:50   Maximum server connections 2
    02/01/2021 09:18:50   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 148, Llog used 53
    
    02/01/2021 09:33:50   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 09:33:50   Mon Feb  1 - loguniq 68, logpos 0x810018, timestamp: 0x230a4b7 Interval: 690
    
    02/01/2021 09:33:50   Maximum server connections 2
    02/01/2021 09:33:50   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 12, Llog used 2
    
    02/01/2021 09:38:50   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 09:38:50   Mon Feb  1 - loguniq 68, logpos 0x81d400, timestamp: 0x230a57c Interval: 691
    
    02/01/2021 09:38:50   Maximum server connections 2
    02/01/2021 09:38:50   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 25, Llog used 13
    
    02/01/2021 09:48:50   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 09:48:50   Mon Feb  1 - loguniq 68, logpos 0x81f018, timestamp: 0x230a58b Interval: 692
    
    02/01/2021 09:48:50   Maximum server connections 2
    02/01/2021 09:48:50   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 19, Llog used 2
    
    02/01/2021 10:03:50   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 10:03:50   Mon Feb  1 - loguniq 68, logpos 0x821018, timestamp: 0x230a59c Interval: 693
    
    02/01/2021 10:03:50   Maximum server connections 2
    02/01/2021 10:03:50   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 3, Llog used 2
    
    
    02/01/2021 10:13:50   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 10:13:50   Mon Feb  1 - loguniq 68, logpos 0x823018, timestamp: 0x230a5df Interval: 694
    
    02/01/2021 10:13:50   Maximum server connections 2
    02/01/2021 10:13:50   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 0, Llog used 2
    
    02/01/2021 10:18:51   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 10:18:51   Mon Feb  1 - loguniq 68, logpos 0x85b018, timestamp: 0x230aaa3 Interval: 695
    
    02/01/2021 10:18:51   Maximum server connections 2
    02/01/2021 10:18:51   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 157, Llog used 56
    
    02/01/2021 10:33:50   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 10:33:50   Mon Feb  1 - loguniq 68, logpos 0x863018, timestamp: 0x230ab5c Interval: 696
    
    02/01/2021 10:33:50   Maximum server connections 2
    02/01/2021 10:33:50   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 22, Llog used 8
    
    02/01/2021 10:38:51   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 10:38:51   Mon Feb  1 - loguniq 68, logpos 0x876520, timestamp: 0x230ad68 Interval: 697
    
    02/01/2021 10:38:51   Maximum server connections 2
    02/01/2021 10:38:51   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 63, Llog used 19
    
    02/01/2021 10:48:51   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 10:48:51   Mon Feb  1 - loguniq 68, logpos 0x878018, timestamp: 0x230ad77 Interval: 698
    
    02/01/2021 10:48:51   Maximum server connections 2
    02/01/2021 10:48:51   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 11, Llog used 2
    
    
    02/01/2021 11:03:51   Checkpoint Completed:  duration was 0 seconds.
    02/01/2021 11:03:51   Mon Feb  1 - loguniq 68, logpos 0x87a018, timestamp: 0x230ad89 Interval: 699
    
    02/01/2021 11:03:51   Maximum server connections 2
    02/01/2021 11:03:51   Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 3, Llog used 2
    
    02/01/2021 11:04:32   Verbose error trapping set, errno = 999, session_id = -1
    02/01/2021 11:04:57   Assert Failed: found errno 999 in session 126
    02/01/2021 11:04:57   IBM Informix Dynamic Server Version 14.10.FC4W1DE
    02/01/2021 11:04:57    Who: Session(126, informix@sandbox.our.company, 766050, 0x4de391d8)
                    Thread(495, sqlexec, 4dde7e48, 8)
                    File: rsdebug.c Line: 3052
    02/01/2021 11:04:57    Action: Use onmode -I to stop verbose error trapping.
    02/01/2021 11:04:57   stack trace for pid 652898 written to /informix/current/tmp/af.5d726a9
    02/01/2021 11:04:57    See Also: /informix/current/tmp/af.5d726a9, shmem.5d726a9.0
    
    
    ===========------------- - - - - - -
    /informix/current/bin/onstat -g ath:
    
    IBM Informix Dynamic Server Version 14.10.FC4W1DE -- On-Line -- Up 2 days 18:02:25 -- 916652 Kbytes
    
    Threads:
     tid     tcb              rstcb            prty status                vp-class       name
     2        50489148         0                1    IO Idle                 3lio*        lio vp 0
     3        504aa3d8         0                1    IO Idle                 4pio*        pio vp 0
     4        504cb3d8         0                1    IO Idle                 5aio*        aio vp 0
     5        504ec3d8         1f4f6c0          1    IO Idle                 6msc*        msc vp 0
     6        5051d3d8         0                1    IO Idle                 7fifo*       fifo vp 0
     7        505b6050         0                1    IO Idle                11aio*        aio vp 1
     8        505d7720         4dde4028         3    sleeping secs: 1        9cpu         main_loop()
     9        506526b8         0                1    running                12soc*        soctcppoll
     10       506748b0         0                2    sleeping forever        1cpu*        soctcplst
     11       506a6370         0                2    sleeping forever        8cpu*        soctcplst
     12       506d3a00         0                2    sleeping forever        9cpu*        soctcplst
     13       50700418         4dde4908         1    sleeping secs: 1        8cpu         flush_sub(0)
     14       50700758         4dde51e8         1    sleeping secs: 1        9cpu         flush_sub(1)
     15       50700a98         0                3    IO Idle                 1cpu*        kaio
     16       507ef550         0                3    IO Idle                 8cpu*        kaio
     17       508120d0         4dde5ac8         2    sleeping secs: 1        9cpu         aslogflush
     18       508b0178         4dde63a8         1    sleeping secs: 92       1cpu         btscanner_0
     19       508cd370         4dde6c88         3    cond wait  ReadAhead    1cpu         readahead_0
     20       508e9568         4dde7568         3    sleeping secs: 1        9cpu         auto_tune
     87       521c0028         0                3    IO Idle                 9cpu*        kaio
     88       52546b50         4de0ad68         3    sleeping secs: 1        1cpu*        onmode_mon
     89       5259e028         4dde8728         3    sleeping secs: 1        9cpu         periodic
     90       52781bf8         4de04bc8         3    sleeping forever        1cpu         memory
     91       5206d028         4de07828         3    sleeping secs: 18       9cpu         session_mgr
     101      52461d48         4de08108         1    sleeping secs: 1        9cpu         dbutil
     102      52676d48         4de0a488         1    sleeping secs: 124      8cpu         dbScheduler
     103      52272d48         0                3    IO Idle                10cpu*        kaio
     104      51f047f0         4de092c8         1    sleeping forever        1cpu         dbWorker1
     105      51f67a10         4de06668         1    sleeping forever        8cpu         dbWorker2
     108      5211f370         4de09ba8         1    cond wait  bp_cond      9cpu         bf_priosweep()
    *495      50b9a028         4dde7e48         1    running                 8cpu         sqlexec
    
    
    
    ===========------------- - - - - - -
    /informix/current/bin/onstat -g stk 495 light:
    
    IBM Informix Dynamic Server Version 14.10.FC4W1DE -- On-Line -- Up 2 days 18:02:25 -- 916652 Kbytes
    
    Stack for thread: 495 sqlexec
     base: 0x0000000050b71000
      len:   102400
       pc: 0x00000000014ac3fa
      tos: 0x0000000050b86b90
    state: running
       vp: 8
    
    0x00000000014ac3fa (oninit) mt_system
    0x00000000014a7dbd (oninit) afhandler
    0x00000000014a9c42 (oninit) affail_interface
    0x0000000000ed9a00 (oninit) check_traperror
    0x0000000000762a41 (oninit) sqerr
    0x000000000079240a (oninit) getaggbyname
    0x00000000006c2a20 (oninit) agg2expr
    0x00000000006c0ffc (oninit) expr2expr
    0x00000000006db4a5 (oninit) ip_exprparse
    0x00000000006e433b (oninit) ip_evalexpr
    0x00000000006ed6fa (oninit) runproc
    0x00000000006f10e3 (oninit) udrlm_spl_execute
    0x0000000000aff1f0 (oninit) udrlm_exec_routine
    0x000000000072d96d (oninit) udr_execute
    0x00000000007339a6 (oninit) exroutine
    0x00000000006093bc (oninit) execproc
    0x000000000071b91e (oninit) aud_execproc
    0x000000000060c013 (oninit) excommand
    0x000000000091cc90 (oninit) dotrstmts
    0x0000000000920d5b (oninit) dotrigs
    0x00000000009240dd (oninit) ferafttrig
    0x0000000000916555 (oninit) dodmlrow
    0x0000000000918604 (oninit) dodelupd
    0x000000000060d45e (oninit) excommand
    0x0000000000abb3eb (oninit) sq_execute_workhorse
    0x0000000000abbc2d (oninit) sq_execute
    0x0000000000b8eeae (oninit) sqmain
    0x00000000015d2e3b (oninit) spawn_thread
    0x0000000001495103 (oninit) th_init_initgls
    0x00000000014dc0bf (oninit) startup
    
    
    
    
    
    ===========------------- - - - - - -
    /informix/current/bin/onstat -u:
    
    IBM Informix Dynamic Server Version 14.10.FC4W1DE -- On-Line -- Up 2 days 18:02:26 -- 916652 Kbytes
    
    Userthreads
    address          flags   sessid   user     tty      wait             tout locks nreads   nwrites
    4dde4028         ---P--D 1        informix -        0                0    0     147      13091
    4dde4908         ---P--F 0        informix -        0                0    0     0        18114
    4dde51e8         ---P--F 0        informix -        0                0    0     0        1070
    4dde5ac8         ---P--- 9        informix -        0                0    0     0        0
    4dde63a8         ---P--B 10       informix -        0                0    0     125      256
    4dde6c88         Y--P--D 11       informix -        508b0560         0    0     9978     0
    4dde7568         ---P--D 12       informix -        0                0    0     0        0
    4dde7e48        *--BP--- 126      informix 2        0                0    10    0        0
    4dde8728         ---P--D 78       informix -        0                0    0     2        0
    4de04bc8         ---P--D 79       informix -        0                0    0     0        0
    4de06668         ---P--- 93       informix -        0                0    1     1673     1707
    4de07828         ---P--D 80       informix -        0                0    0     0        0
    4de08108         ---P--- 90       informix -        0                0    1     14       0
    4de092c8         ---P--- 92       informix -        0                0    1     1906     2618
    4de09ba8         Y--P--D 96       informix -        4429cd48         0    0     0        0
    4de0a488         ---P--- 91       informix -        0                0    2     284      885
    4de0ad68         ---P--D 77       informix -        0                0    0     0        0
     17 active, 128 total, 70 maximum concurrent
    
    
    
    ===========------------- - - - - - -
    /informix/current/bin/onstat -g ses 126:
    
    IBM Informix Dynamic Server Version 14.10.FC4W1DE -- On-Line -- Up 2 days 18:02:26 -- 916652 Kbytes
    
    session           effective                                          #RSAM    total      used       dynamic
    id       user     user      tty      pid      hostname               threads  memory     memory     explain
    126      informix -         2        766050   sandbox.our.company 1        245760     236272     off
    
    Program :
    /informix/IDS14.10.FC4W1/bin/dbaccess
    
    tid      name     rstcb            flags    curstk   status
    495      sqlexec  4dde7e48         --BP---  13424    running-
    
    Memory pools    count 2
    name         class addr              totalsize  freesize   #allocfrag #freefrag
    126          V     50e0c040         241664     8744       209        11
    126*O0       V     52b3c040         4096       744        1          1
    
    name             free       used         name             free       used
    overhead         0          6704         scb              0          144
    opentable        0          14616        filetable        0          2648
    ru               0          600          log              0          16536
    temprec          0          7328         ralloc           0          137144
    gentcb           0          1600         ostcb            0          2992
    sqscb            0          24448        sql              0          3184
    hashfiletab      0          552          osenv            0          2576
    buft_buffer      0          1816         sqtcb            0          9920
    fragman          0          2968         sapi             0          288
    udr              0          208
    
    sqscb info
    scb              sqscb            optofc   pdqpriority optcompind  directives
    4e7901c0         50c50028         0        0           2           1
    
    Sess       SQL            Current            Iso Lock       SQL  ISAM F.E.
    Id         Stmt type      Database           Lvl Mode       ERR  ERR  Vers  Explain
    126                       user_auth_db CR  Not Wait   -999 0    9.24  Off
    
    Stored procedure stack :
    
       context            proc-counter       opcode name
       ------------------------------------------------------------------
       0x0000000052a75c48 0x52a585e0+0x0010 EXPR       user_auth_db:empl_reg_usr_del_spl
    
    Current SQL statement (3) in procedure user_auth_db:empl_reg_usr_del_spl
       proc-counter 0x52a585e0 opcode EXPR
    
    (<procedure> strip_dashes, i_ssn)
    
    Last parsed SQL statement :
      delete from employee where emp_num = 63
    
    
    
    ===========------------- - - - - - -
    /informix/current/bin/onstat -g env 126:
    
    IBM Informix Dynamic Server Version 14.10.FC4W1DE -- On-Line -- Up 2 days 18:02:26 -- 916652 Kbytes
    
    .
    .
    .
    
    ​

    This goes on for about 53k lines, so not sure how much of that you want to see, or if there are specific sections that you think might be more likely to point to the problem.



    ------------------------------
    Mark Collins
    ------------------------------



  • 9.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 11:27 AM

    Very had to read ......

     

    Why is the stack showing udr_execute, AFAIK that path should only be for non-standard datatypes.   Thought we were doing a simple update

     

    Cheers

    Paul

     

     

     






  • 10.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 11:50 AM
    I believe that is due to the triggers calling stored procedures that reside in a different database (user_auth_db vs. user_db).

    I have disabled the triggers on the employee table, and now I am able to update and delete rows without the -999 error.

    This sandbox instance was created by dbexport a few databases from our existing instance and dbimporting them into the new instance, so it is likely that I've missed some component that is necessary for the whole thing to work.  I will be looking at the triggers in more detail now, insuring that all of their dependencies are in place.

    Thanks to all for the help in getting this far.

    ------------------------------
    Mark Collins
    ------------------------------



  • 11.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 11:59 AM

    Onmode –I and stack traces are your friend J

     






  • 12.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 11:29 AM
    Problem looking to be an aggregate function called from within the trigger UDR now being a remote aggregate function (residing in a different database).
    Might simply be a consequence of the UDRs themselves residing in different DB?

    ------------------------------
    Andreas Legner
    ------------------------------



  • 13.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 11:53 AM
    I'm not certain whether it is that the triggers call procedures that reside in a different database, or if there is something else that is missing.  The current 11.50 production database, on which this sandbox is based, does have the triggers calling procedures in remote databases, so I know that part was working in 11.50.  I will be looking at these in more detail now to see what, if anything, I missed in trying to recreate the environment in the sandbox.

    Thanks for pointing me in the correct direction.

    ------------------------------
    Mark Collins
    ------------------------------



  • 14.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 12:12 PM
    Found it.

    The trigger calls a procedure in a remote database.  So far so good.  That procedure then invokes a function to strip off the '(', ')', and '-' from telephone numbers.  That function did not exist in the remote database.  Added it, and now updates and deletes against the employee table work just fine with the triggers enabled.

    So in this case, the -999 was referring to a user-defined function that was not defined.

    ------------------------------
    Mark Collins
    ------------------------------



  • 15.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 12:26 PM

    So -999 was accurate then

     

    Cheers

    Paul

     






  • 16.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 11:31 AM

    Search for the "onstat –g ses 126" in that af file.

     






  • 17.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 11:44 AM
    ===========------------- - - - - - -
    /informix/current/bin/onstat -g ses 126:
    
    IBM Informix Dynamic Server Version 14.10.FC4W1DE -- On-Line -- Up 2 days 18:02:26 -- 916652 Kbytes
    
    session           effective                                          #RSAM    total      used       dynamic
    id       user     user      tty      pid      hostname               threads  memory     memory     explain
    126      informix -         2        766050   sandbox02.our.company 1        245760     236272     off
    
    Program :
    /informix/IDS14.10.FC4W1/bin/dbaccess
    
    tid      name     rstcb            flags    curstk   status
    495      sqlexec  4dde7e48         --BP---  13424    running-
    
    Memory pools    count 2
    name         class addr              totalsize  freesize   #allocfrag #freefrag
    126          V     50e0c040         241664     8744       209        11
    126*O0       V     52b3c040         4096       744        1          1
    
    name             free       used         name             free       used
    overhead         0          6704         scb              0          144
    opentable        0          14616        filetable        0          2648
    ru               0          600          log              0          16536
    temprec          0          7328         ralloc           0          137144
    gentcb           0          1600         ostcb            0          2992
    sqscb            0          24448        sql              0          3184
    hashfiletab      0          552          osenv            0          2576
    buft_buffer      0          1816         sqtcb            0          9920
    fragman          0          2968         sapi             0          288
    udr              0          208
    
    sqscb info
    scb              sqscb            optofc   pdqpriority optcompind  directives
    4e7901c0         50c50028         0        0           2           1
    
    Sess       SQL            Current            Iso Lock       SQL  ISAM F.E.
    Id         Stmt type      Database           Lvl Mode       ERR  ERR  Vers  Explain
    126                       user_auth_db CR  Not Wait   -999 0    9.24  Off
    
    Stored procedure stack :
    
       context            proc-counter       opcode name
       ------------------------------------------------------------------
       0x0000000052a75c48 0x52a585e0+0x0010 EXPR       user_auth_db:empl_reg_usr_del_spl
    
    Current SQL statement (3) in procedure user_auth_db:empl_reg_usr_del_spl
       proc-counter 0x52a585e0 opcode EXPR
    
    (<procedure> strip_dashes, i_ssn)
    
    Last parsed SQL statement :
      delete from employee where emp_num = 63
    
    
    
    ===========------------- - - - - - -
    /informix/current/bin/onstat -g env 126:
    
    IBM Informix Dynamic Server Version 14.10.FC4W1DE -- On-Line -- Up 2 days 18:02:26 -- 916652 Kbytes
    
    Environment for session 126:
    
    Variable            Value [values-list]
    CLIENT_LOCALE       en_US.8859-1
    CLNT_PAM_CAPABLE    1
    DBDELIMITER         |
    DBPATH              .
                        [.]
                        [//ol_informix1410]
    DBPRINT             lp -s
    DBTEMP              /tmp
    GL_USEGLU           1
    IGNORE_UNDERFLOW    1
    INFORMIXDIR         /informix/current
                        [/informix/current]
                        [/usr/informix]
    INFORMIXSERVER      ol_informix1410
    INFORMIXSQLHOSTS    /informix/current/etc/sqlhosts.ol_informix1410
    INFORMIXTERM        terminfo
    LANG                en_US.UTF-8
    LC_COLLATE          en_US.UTF-8
    LC_CTYPE            en_US.UTF-8
    LC_MONETARY         en_US.UTF-8
    LC_NUMERIC          en_US.UTF-8
    LC_TIME             en_US.UTF-8
    LKNOTIFY            yes
    LOCKDOWN            no
    NODEFDAC            no
                        [no]
                        [no]
    ONCONFIG            onconfig.ol_informix1410
    PATH                /informix/current/bin:/informix/current/extend/krakatoa/jre
                         /bin:/informix/current/bin:/informix/current/extend/krakat
                         oa/jre/bin:/home/informix/.local/bin:/home/informix/bin:/u
                         sr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/smile/con
                         fig
    SERVER_LOCALE       en_US.819
    SHELL               /bin/bash
    SUBQCACHESZ         10
    TERM                xterm
                        [xterm]
                        [dumb]
    TERMCAP             /etc/termcap
    
    
    
    
    ===========------------- - - - - - -
    /informix/current/bin/onstat -g sql 126:
    
    IBM Informix Dynamic Server Version 14.10.FC4W1DE -- On-Line -- Up 2 days 18:02:26 -- 916652 Kbytes
    
    
    Sess       SQL            Current            Iso Lock       SQL  ISAM F.E.
    Id         Stmt type      Database           Lvl Mode       ERR  ERR  Vers  Explain
    126                       user_auth_db CR  Not Wait   -999 0    9.24  Off
    
    Stored procedure stack :
    
       context            proc-counter       opcode name
       ------------------------------------------------------------------
       0x0000000052a75c48 0x52a585e0+0x0010 EXPR       user_auth_db:empl_reg_usr_del_spl
    
    Current SQL statement (3) in procedure user_auth_db:empl_reg_usr_del_spl
       proc-counter 0x52a585e0 opcode EXPR
    
    (<procedure> strip_dashes, i_ssn)
    
    Last parsed SQL statement :
      delete from employee where emp_num = 63
    
    
    
    ===========------------- - - - - - -
    /informix/current/bin/onstat -g stm 126:
    
    IBM Informix Dynamic Server Version 14.10.FC4W1DE -- On-Line -- Up 2 days 18:02:26 -- 916652 Kbytes
    
    session 126        ---------------------------------------------------------------
    sdblock          heapsz     flags statement ('*' = Open cursor)
    52d17028         72528      -----  delete from employee where emp_num = 63
    52d172e8         51760      -----  <SPL(user_db:567), stmt(0):SELECT >
    52d175a8         4976       -----  <SPL(user_auth_db:561), stmt(1):EXPRESSION >
    
    
    
    ===========------------- - - - - - -
    ​


    ------------------------------
    Mark Collins
    ------------------------------



  • 18.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 09:49 AM
    Paul's suggestion -- onmode -I 999 -- (capital-eye) was also going to be my suggestion, too.

    One other thing I'd check is that the executables are branded correctly, setuid root where they need to be, correct ownerships, etc.

    I'd also be curious about what's shown in a dbschema -d [db] -t employee -ss

    ------------------------------
    TOM GIRSCH
    ------------------------------



  • 19.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 10:00 AM

    I forgot to mention you can set ADEBUG=1 before you start the engine, then the engine should hang on the AF. Very useful at times. Onmode –I will release the 'hang'

     

    Cheers

    Paul

     






  • 20.  RE: -999 Not implemented yet.

    Posted Mon February 01, 2021 10:35 AM
    Tom,

    The dbschema output:

    { TABLE "db_user".employee row size = 1611 number of columns = 325 index size = 66 }
    
    create table "db_user".employee
      (
        emp_num smallint,
        lastname char(30),
        firstname char(30),
        middleinit char(30),
        dob date,
        age smallint,
        inpay money(6,2),
        intimes smallint,
        inint smallint,
        address char(35),
        city char(30),
        state char(2),
        zip char(10),
        ssn char(11),
        freq char(1),
        hourly char(1),
        stat2 money(6,2),
        retir char(1),
        insur char(1),
        adtime smallint,
        merdis smallint,
        fed_stat char(1),
        fed_exemp decimal(3),
        st_stat char(1),
        st_exemp decimal(2),
        flexcalc char(1),
        addf money(6,2),
        adds money(6,2),
        aip decimal(4),
        prognum char(6),
        lastadvdate date,
        nextadvdate date,
        div char(5),
        func char(15),
        class char(5),
        grade_step integer,
        payplan char(1),
        positnum char(8),
        credun char(8),
        hlth char(2),
        dis char(1),
        hours decimal(6),
        hourlyrate money(4,2),
        ovthours decimal(4),
        suphrlyrate money(4,2),
        supp money(6,2),
        normalgros money(8,2),
        gross money(8,2),
        totf money(6,2),
        totf2 money(6,2),
        fica money(6,2),
        fed money(6,2),
        fed2 integer,
        stat money(6,2),
        wh5 money(6,2),
        wh6 money(6,2),
        wh7 money(6,2),
        wh8 money(6,2),
        wh9 money(6,2),
        wh10 money(10,2),
        wh11 money(6,2),
        wh12 money(6,2),
        wh13 money(6,2),
        wh14 money(6,2),
        wh15 money(6,2),
        wh16 money(6,2),
        wh17 money(6,2),
        wh18 money(6,2),
        wh19 money(6,2),
        wh20 money(6,2),
        wh21 money(6,2),
        wh22 money(6,2),
        wh23 money(6,2),
        wh24 money(6,2),
        wh25 money(6,2),
        net money(8,2),
        net2 money(10,2),
        calcmon money(10,2),
        calcsix decimal(8),
        calcthir decimal(8),
        calcbucket integer,
        fedwhcalc money(10,2),
        statwhcalc money(10,2),
        totflexcalc money(6,2),
        newretwh money(6,2),
        oldretwh money(6,2),
        calcretir money(8,2),
        swtch char(1),
        checkdate date,
        checknum integer,
        banknum char(2),
        percent smallint,
        acct1 decimal(10),
        amt1 money(8,2),
        per1 decimal(4),
        acct2 decimal(10),
        amt2 money(8,2),
        per2 decimal(4),
        acct3 decimal(10),
        amt3 money(8,2),
        per3 decimal(4),
        acct4 decimal(10),
        amt4 money(8,2),
        per4 decimal(4),
        acct5 decimal(10),
        amt5 money(8,2),
        per5 decimal(4),
        amt6 money(8,2),
        suppind char(1),
        suppamt money(5,2),
        tract1 decimal(10),
        nmil1 smallint,
        ratem1 decimal(3,3),
        milamt1 money(6,2),
        pdamt1 money(6,2),
        totamt1 money(8,2),
        tract2 decimal(10),
        nmil2 smallint,
        ratem2 decimal(3,3),
        milamt2 money(6,2),
        pdamt2 money(6,2),
        totamt2 money(8,2),
        tract3 decimal(10),
        nmil3 smallint,
        ratem3 decimal(3,3),
        milamt3 money(6,2),
        pdamt3 money(6,2),
        totamt3 money(8,2),
        tottrav money(8,2),
        ledgerno char(3),
        empe_ficapct decimal(4),
        medic_ficapct decimal(4),
        supovtpay money(6,2),
        ovtpay money(6,2),
        insurtax char(1),
        dentaltype char(1),
        taxfc money(6,2),
        flexdate date,
        countyno smallint,
        tips money(6,2),
        pager char(1),
        overfica char(1),
        banknam char(20),
        bankid char(8),
        bankck char(1),
        bankacct char(17),
        prenotcod char(2),
        dirdep char(1),
        lastdddat date,
        wh5t money(6,2),
        wh6t money(6,2),
        wh7t money(6,2),
        wh8t money(6,2),
        wh9t money(6,2),
        wh11t money(6,2),
        wh13t money(6,2),
        wh26 money(6,2),
        wh27 money(6,2),
        wh28 money(6,2),
        wh29 money(6,2),
        wh30 money(6,2),
        transt money(6,2),
        visiont money(6,2),
        wh10t money(6,2),
        wh12t money(6,2),
        wh14t money(6,2),
        wh15t money(6,2),
        wh16t money(6,2),
        wh17t money(6,2),
        wh18t money(6,2),
        wh19t money(6,2),
        wh20t money(6,2),
        splitind char(1),
        wh31 money(6,2),
        wh32 money(6,2),
        wh33 money(6,2),
        wh34 money(6,2),
        wh35 money(6,2),
        wh36 money(6,2),
        wh37 money(6,2),
        wh38 money(6,2),
        wh39 money(6,2),
        wh40 money(6,2),
        wh41 money(6,2),
        wh42 money(6,2),
        wh43 money(6,2),
        wh44 money(6,2),
        wh45 money(6,2),
        wh46 money(6,2),
        wh47 money(6,2),
        wh48 money(6,2),
        wh49 money(6,2),
        wh50 money(6,2),
        wh21t money(6,2),
        wh22t money(6,2),
        wh23t money(6,2),
        wh24t money(6,2),
        wh25t money(6,2),
        wh26t money(6,2),
        wh27t money(6,2),
        wh28t money(6,2),
        wh29t money(6,2),
        wh30t money(6,2),
        wh31t money(6,2),
        wh32t money(6,2),
        wh33t money(6,2),
        wh34t money(6,2),
        wh35t money(6,2),
        wh36t money(6,2),
        wh37t money(6,2),
        wh38t money(6,2),
        wh39t money(6,2),
        wh40t money(6,2),
        wh41t money(6,2),
        wh42t money(6,2),
        wh43t money(6,2),
        wh44t money(6,2),
        wh45t money(6,2),
        wh46t money(6,2),
        wh47t money(6,2),
        wh48t money(6,2),
        wh49t money(6,2),
        wh50t money(6,2),
        wh4 money(6,2),
        wh4t money(6,2),
        totcheck money(10,2),
        retamtset money(8,2),
        otherearn money(10,2),
        dirdepcode char(2),
        lvsort char(5),
        legl char(1),
        medc money(6,2),
        overmedc char(1),
        lwophrs decimal(6,2),
        talhrs decimal(6,2),
        stdhrs decimal(6,2),
        rounder decimal(12,4),
        eic money(6,2),
        incre smallint,
        dkflag char(2),
        trans money(6,2),
        vision money(8,2),
        visiontype char(2),
        depend char(2),
        termdate date,
        education char(1),
        child_life char(2),
        spend_type char(2),
        std_wait char(2),
        dfc2 money(8,2),
        spa2 money(8,2),
        dl2 money(8,2),
        ltc money(8,2),
        dfc2t money(8,2),
        spa2t money(8,2),
        dl2t money(8,2),
        ltct money(8,2),
        ltctype char(1),
        basepay money(10,2),
        salsupp money(8,2),
        deptid char(10),
        ers_num char(8),
        hiredate date,
        specill money(8,2),
        spcicode char(2),
        wspit money(8,2),
        mvsupp money(8,2),
        mvsuppann money(8,2),
        totperpay money(8,2),
        gender char(1),
        rectype char(4),
        rectypdat date,
        nsf char(1),
        pullflag char(1),
        suffix char(3),
        add2 char(35),
        erschandat date,
        erscode char(2),
        interadd char(50),
        internafl char(1),
        ersperc decimal(4),
        paytype char(2),
        erseffdat date,
        jobcode char(2),
        shbpelig char(1),
        spci2code char(2),
        specill2 money(8,2),
        spa3 money(8,2),
        hltsav money(8,2),
        spi2t money(8,2),
        spa3t money(8,2),
        hltsat money(8,2),
        division char(3),
        tdirdep char(1),
        banknum2 char(2),
        banknam2 char(20),
        bankid2 char(8),
        bankck2 char(1),
        bankacct2 char(17),
        prenotcod2 char(2),
        lastdddat2 date,
        ograde_step char(5),
        furpay money(10,2),
        furcode integer,
        tra char(1),
        gsepper decimal(5,2),
        cktype char(1),
        per457 decimal(5,2),
        per401 decimal(5,2),
        ddapprove char(1),
        ddappr_date date,
        ddctrycode char(3),
        tddapprove char(1),
        tddappr_date date,
        tddctrycode char(3),
        email char(72),
        rehire_date date,
        rehire char(1),
        jobstat char(1),
        origbasepay money(16,2),
        origsalsupp money(16,2),
        ppsup money(6,2),
        eict money(6,2),
        flsa money(8,2),
        gsepded char(1)
      ) extent size 2000 next size 150 lock mode row;
    
    revoke all on "db_user".employee from "public" as "db_user";
    
    
    create index "db_user".emp_calc on "db_user".employee (calcretir)
        using btree  in indexdbs;
    create index "db_user".emp_ers on "db_user".employee (ers_num)
        using btree  in indexdbs;
    create index "db_user".emp_grad on "db_user".employee (grade_step)
        using btree  in indexdbs;
    create index "db_user".emp_incre on "db_user".employee (incre)
        using btree  in indexdbs;
    create index "db_user".emp_prog on "db_user".employee (prognum)
        using btree  in indexdbs;
    create index "db_user".emp_ssn on "db_user".employee (ssn) using
        btree  in indexdbs;
    
    
    create trigger "db_user".empl_reg_usr_ins insert on "db_user".employee
        referencing new as n
        for each row
            (
            execute procedure user_audit_db:"db_user".empl_reg_usr_ins_spl(n.ers_num
        ,"db_user".curr_region(),n.ssn ,n.lastname ,n.firstname ,n.middleinit
        ,n.suffix ,n.email ,n.freq ));
    
    create trigger "db_user".empl_reg_usr_upd update of ers_num,ssn,
        lastname,firstname,middleinit,suffix,email,freq on "db_user"
        .employee referencing old as o new as n
        for each row
            (
            execute procedure user_audit_db:"db_user".empl_reg_usr_upd_spl(n.ers_num
        ,"db_user".curr_region(),n.ssn ,n.lastname ,n.firstname ,n.middleinit
        ,n.suffix ,n.email ,n.freq ));
    
    create trigger "db_user".empl_reg_usr_del delete on "db_user".employee
        referencing old as o
        for each row
            (
            execute procedure user_audit_db:"db_user".empl_reg_usr_del_spl(o.ers_num
        ,"db_user".curr_region(),o.ssn ));
    ​

    I have confirmed that the procedures empl_reg_usr_del_spl, empl_reg_usr_ins_spl, and empl_reg_usr_upd_spl all are present in the user_audit_db, and all are owned by user "db_user".  Also, "public" has execute permission on all three of these procedures.

    ------------------------------
    Mark Collins
    ------------------------------