CAC 2017-04-22

threadz

Session hung during 'lst >'; unresponsive to ^C.

On console 'bce','dump -lg', 'esd'; reboot

azm

azm:  sld 1
  ERF 1   in directory >dumps dumped at 04/22/17  1117.1 pst Sat.
  System-ID MR12.6e Version-ID MR12.6e
Proc   0 DBR  17170450 running        on cpu a   Initializer.SysDaemon.z

azm:  lsp
Proc   0 DBR  17170450 running        on cpu a   Initializer.SysDaemon.z
Proc   1 DBR     52400 ready     last on cpu a   Idle.SysControl.a
Proc   2 DBR     52401 running        on cpu b   Idle.SysControl.b
Proc   3 DBR  16676014 blocked   last on cpu a   SyserrLogger.SysDaemon.z
Proc   4 DBR  16677454 blocked   last on cpu a   MCS_Timer_Daemon.SysDaemon.z
Proc   5 DBR  16700434 blocked   last on cpu b   IO.SysDaemon.z
Proc   6 DBR  16700554 blocked   last on cpu a   Backup.SysDaemon.z
Proc   7 DBR  16700654 blocked   last on cpu a   IO.SysDaemon.z
Proc   8 DBR  16700774 blocked   last on cpu a   Utility.SysDaemon.z
Proc   9 DBR  16701174 blocked   last on cpu a   Volume_Dumper.Daemon.z
Proc  10 DBR  16703514 ready     last on cpu b   Repair.SysAdmin.a
Proc  11 DBR  16710014 ready     last on cpu a   Repair.SysAdmin.a

azm:  slp 10
Process  10, Repair.SysAdmin.a, DBR  16703514

azm:  stack 234

Reverse trace of >pdd>!BLbDcKhBBBBBBB>stack_4 (Seg 234)
Number of stack frames 10.
Stack begin = 234|2000 Stack end = 234|22100
FRAME       RETURN_PTR
234|20160   311|50344    >sss>bound_fs_util_$fs_star_|4542
234|16240   311|52202    >sss>bound_fs_util_$fs_star_|6400
234|14320   311|52202    >sss>bound_fs_util_$fs_star_|6400
234|12400   311|52202    >sss>bound_fs_util_$fs_star_|6400
234|10460   311|52202    >sss>bound_fs_util_$fs_star_|6400
234|6400    311|47726    >sss>bound_fs_util_$fs_star_|4124
234|3640    305|42334    >sss>bound_fscom1_$list_sub_tree|1614
234|2700    276|2102     >sl1>bound_multics_bce_$command_processor_|2102
234|2400    270|34523    >sss>bound_command_loop_$listen_|555
234|2000    243|705      >sss>bound_process_init_$initialize_process_|705
Previous stack frame 77777|1

azm:  stack 230

Reverse trace of >sl1>stack_0.013 (Seg 230)
Number of stack frames 4.
Stack begin = 230|100 Stack end = 230|4320
FRAME       RETURN_PTR
230|3200    144|10410    bound_segment_control$lock|2176
230|540     145|25123    bound_system_security$dc_find|12135
230|220     130|61165    bound_file_system$star_|561
230|100     262|3123     >sl1>hcs_|3123
Previous stack frame 234|20160

azm:  stack 230 -ag

Reverse trace of >sl1>stack_0.013 (Seg 230)
Number of stack frames 4.
Stack begin = 230|100 Stack end = 230|4320
FRAME       RETURN_PTR
230|3200    144|10410    bound_segment_control$lock|2176

          Entry ptr 144|7363 bound_segment_control$lock|1151
          Operator/Link ptr 41|21736
          Arg ptr 230|2046
          ARG  1: 442|0  >ldd>system_library_unbundled>source
          ARG  2: 000000000000

230|540     145|25123    bound_system_security$dc_find|12135

          Entry ptr 145|14003 bound_system_security$dc_find|1015
          Operator/Link ptr 41|21736
          Arg ptr 230|506
          ARG  1: ">library_dir_dir>system_library_unbundled>source
\c                                        "
          ARG  2: 77777|1  NULL POINTER
          ARG  3: 000000000000

230|220     130|61165    bound_file_system$star_|561

          Entry ptr 130|60443 bound_file_system$star_|37
          Operator/Link ptr 41|21736
          Arg ptr 234|21256
          ARG  1: ">library_dir_dir>system_library_unbundled>source
\c
\c                               "
          ARG  2: "**                              "
          ARG  3: 3e0
          ARG  4: 314|0  >pdd>!BLbDcKhBBBBBBB>!BBBKLNGxQqGHFW.temp
          ARG  5: 152
          ARG  6: 000000000052  000000000060
          ARG  7: 234|21120  >pdd>!BLbDcKhBBBBBBB>stack_4|21120
          ARG  8: 4303372320

230|100     262|3123     >sl1>hcs_|3123

          Entry ptr 44|6266 bound_tc_priv$pxss|6266
          Operator/Link ptr 16|17514
          Arg ptr 234|21256
          ARG  1: ">library_dir_dir>system_library_unbundled>source
\c
\c                               "
          ARG  2: "**                              "
          ARG  3: 3e0
          ARG  4: 314|0  >pdd>!BLbDcKhBBBBBBB>!BBBKLNGxQqGHFW.temp
          ARG  5: 152
          ARG  6: 000000000052  000000000060
          ARG  7: 234|21120  >pdd>!BLbDcKhBBBBBBB>stack_4|21120
          ARG  8: 4303372320

Previous stack frame 234|20160

azm:

mem_lock contention

mutrace: Showing statistics for process dps8 (PID: 28256).
mutrace: 48 mutexes used.

Mutex #4 (0x0x737750) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_mutex_lock+0x11c) [0x7f9b0b42bdbc]
    ./dps8() [0x4442ab]

Mutex #3 (0x0x737728) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_mutex_lock+0x11c) [0x7f9b0b42bdbc]
    ./dps8() [0x40a6ce]

Mutex #2 (0x0x736910) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_mutex_lock+0x11c) [0x7f9b0b42bdbc]
    ./dps8() [0x439b32]

Mutex #28 (0x0x948110) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_mutex_init+0x1b0) [0x7f9b0b42b9ca]
    ./dps8() [0x444738]

Mutex #8 (0x0x940e40) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_mutex_init+0x1b0) [0x7f9b0b42b9ca]
    ./dps8() [0x444b28]

Mutex #7 (0x0x940dc8) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_mutex_init+0x1b0) [0x7f9b0b42b9ca]
    ./dps8() [0x444b28]

Mutex #35 (0x0x9483f8) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_mutex_init+0x1b0) [0x7f9b0b42b9ca]
    ./dps8() [0x4443b7]

Mutex #33 (0x0x948330) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_mutex_init+0x1b0) [0x7f9b0b42b9ca]
    ./dps8() [0x4443b7]

Mutex #27 (0x0x941728) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_mutex_init+0x1b0) [0x7f9b0b42b9ca]
    ./dps8() [0x444b28]

Mutex #32 (0x0x9482d0) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_mutex_init+0x1b0) [0x7f9b0b42b9ca]
    ./dps8() [0x44436c]

mutrace: Showing 10 mutexes in order of (write) contention count:

 Mutex #   Locked  Changed    Cont. cont.Time[ms] tot.Time[ms] avg.Time[ms] Flags
       4 2524242470 25168770 24154525    146635.727   402051.004        0.000 M-.--.
       3  1204202      236        8         0.891    10154.055        0.008 M-.--.
       2   853079    35746        5         0.009      215.606        0.000 M-.--.
      28    47457    19322        3         0.037      170.629        0.004 M-.--.
       8    23761    15840        0         0.000      389.931        0.016 M-.--.
       7     3493     2328        0         0.000       47.973        0.014 M-.--.
      35     7400     1658        0         0.000       12.164        0.002 M-.--.
      33    10758      826        0         0.000        8.119        0.001 M-.--.
      27      811      540        0         0.000       49.538        0.061 M-.--.
      32     8419      277        0         0.000        6.783        0.001 M-.--.
     ...      ...      ...      ...           ...          ...          ... ||||||
                                                                            /|||||
          Object:                                      M = Mutex, W = RWLock /||||
           State:                                  x = dead, ! = inconsistent /|||
             Use:                                  R = used in realtime thread /||
      Mutex Type:                   r = RECURSIVE, e = ERRORCHECK, a = ADAPTIVE /|
  Mutex Protocol:                                       i = INHERIT, p = PROTECT /
     RWLock Kind:  r = PREFER_READER, w = PREFER_WRITER, W = PREFER_WRITER_NONREC 

mutrace: Note that rwlocks are shown as two lines: write locks then read locks.

mutrace: Note that the flags column R is only valid in --track-rt mode!

mutrace: 43 condition variables used.

Condvar #23 (0x0x9480e0) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_cond_init+0x122) [0x7f9b0b42c4df]
    ./dps8() [0x444761]

Condvar #3 (0x0x940e10) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_cond_init+0x122) [0x7f9b0b42c4df]
    ./dps8() [0x444b53]

Condvar #30 (0x0x9483c8) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_cond_init+0x122) [0x7f9b0b42c4df]
    ./dps8() [0x4443e0]

Condvar #28 (0x0x948300) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_cond_init+0x122) [0x7f9b0b42c4df]
    ./dps8() [0x4443e0]

Condvar #2 (0x0x940d98) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_cond_init+0x122) [0x7f9b0b42c4df]
    ./dps8() [0x444b53]

Condvar #22 (0x0x9416f8) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_cond_init+0x122) [0x7f9b0b42c4df]
    ./dps8() [0x444b53]

Condvar #8 (0x0x941068) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_cond_init+0x122) [0x7f9b0b42c4df]
    ./dps8() [0x444b53]

Condvar #5 (0x0x940f00) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_cond_init+0x122) [0x7f9b0b42c4df]
    ./dps8() [0x444b53]

Condvar #6 (0x0x940f78) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_cond_init+0x122) [0x7f9b0b42c4df]
    ./dps8() [0x444b53]

Condvar #7 (0x0x940ff0) first referenced by:
    /usr/local/lib/libmutrace.so(pthread_cond_init+0x122) [0x7f9b0b42c4df]
    ./dps8() [0x444b53]

mutrace: Showing 10 condition variables in order of wait contention count:

  Cond #    Waits  Signals    Cont. tot.Time[ms] cont.Time[ms] avg.Time[ms] Flags
      23    18957    19000    18908  1324334.198         0.000        0.000     -.
       3     7921    15840        0  1322466.518         0.000        0.000     -.
      30     3125     1151        0   587503.217         0.000        0.000     -.
      28     1171     8416        0   223890.846         0.000        0.000     -.
       2     1165     2328        0  1314955.348         0.000        0.000     -.
      22      271      540        0  1323867.783         0.000        0.000     -.
       8      122      242        0  1274738.367         0.000        0.000     -.
       5        4        6        0   592409.592         0.000        0.000     -.
       6        4        6        0   596413.462         0.000        0.000     -.
       7        4        6        0   600009.817         0.000        0.000     -.
     ...      ...      ...      ...          ...           ...          ...     ||
                                                                                /|
           State:                                     x = dead, ! = inconsistent /
             Use:                                     R = used in realtime thread 

mutrace: Note that the flags column R is only valid in --track-rt mode!

mutrace: Total runtime is 1328023.880 ms.

mutrace: Results for SMP with 4 processors.

Lock variable usage in Multics

MITascii/library_dir_dir/system_library_tools/source/bound_prtdim_.s.archive/prt_conv_.alm:

          ldac      lb|pci.pos          get previous position of incomplete line
          ldqc      lb|pci.pos          save line position
          sta       lb|pci.pos          and restore it

          ldac      lb|pci.slew_residue any more lines to slew?
          sta       lb|pci.slew_residue save residue
          szn       lb|pci.slew_residue

          ldac      lb|pci.esc_state    get and clear state variable
          lda       lb|pci.esc_state    get state of ESC processing
          aos       lb|pci.esc_state    set state to 1
          stca      lb|pci.esc_state,70 save in state variable
bad_esc:  stz       lb|pci.esc_state    restate state variable
          sta       lb|pci.esc_state    ..

          ldac      lb|pci.func         get function code
          stq       lb|pci.func         and restore it

          sznc      endline             end of line char encountered?
          stz       endline   clear end of line char switch
          stc2      endline             and set flag again

MITascii/library_dir_dir/system_library_unbundled/source/bound_multics_emacs_.s.archive/e_lap_.lap

          (ldac     ap|-5)              ;pointpos is len

MITascii/library_dir_dir/system_library_unbundled/source/bound_lisp_intrprtr_.2.s.archive/lisp_.alm

          ldac      lisp_static_vars_$binding_reversal_flag test & clear intr lock
          stc1      lisp_static_vars_$binding_reversal_flag lock interrupts

MITascii/library_dir_dir/system_library_unbundled/source/bound_lisp_intrprtr_.2.s.archive/lisp_alloc_.alm

          ldac      lp|alloc_fault_word
          stc1      lp|alloc_fault_word           " inhibit interrupts.
          stx1      lp|alloc_fault_word
          ldx0      lp|alloc_fault_word " and return to restart point of allocation routine.
          ldx5      lb|alloc_fault_word kludge saving restart address in x5
          stx3      lb|alloc_fault_word
          stx5      lb|alloc_fault_word restore stc1 word to original state

          entry     get_fault_word
get_fault_word:                         " subroutine to get a copy of alloc_fault_word, and zero it at the same time.
                                        " must be done in a way such that interrupts don't foul it up.
                                        " interrupts can or new things into the fault word...
          stz       ap|2,*              " zero result.
gfw_lp:   lda       lp|alloc_fault_word " get fault word.
          orsa      ap|2,*              " or bits gotten into result.
          ersa      lp|alloc_fault_word " and clear those bits in the fault word.
          tnz       gfw_lp-*,ic         " if more bits turned on since two insts. ago, get them.
          short_return

          entry     set_fault
set_fault:
          lda       ap|2,*
          orsa      lp|alloc_fault_word           " set fault on.
          short_return

          stx0      lp|alloc_fault_word

MITascii/library_dir_dir/system_library_1/source/bound_iom_support.s.archive/iom_connect.alm

          ldac      bp|iom_data.imw_lock
          sta       bp|iom_data.imw_lock
          sznc      bp|iom_data.imw_lock
          aos       bp|iom_data.imw_lock" was zero from sznc, is now 1
          sta       bp|iom_data.imw_lock

          ldac      sb|per_device.status
          stx7      sb|per_device.status" fill in channel mailbox

          stac      bp|iom_data.per_iom+per_iom.lock,x3
          szn       bp|iom_data.per_iom+per_iom.lock,x3
          stacq     bp|iom_data.per_iom+per_iom.lock,x3 " start this over again

MITascii/library_dir_dir/system_library_1/source/bound_iom_support.s.archive/iom_overhead.pl1

               string (iom_fault_status) = ldac (addr (status_queue.status (i)));
          call set_dcw_lpw (iom, system_fault_channel,
               addr (iom_mailbox_seg.system_fault (iom)),
               dimension (addr (iom_mailbox_seg.system_fault (iom)) -> status_queue.status, 1));
          tally = dimension (qp -> status_queue.status, 1);
Unless otherwise stated, the content of this page is licensed under Creative Commons Attribution-ShareAlike 3.0 License