CAC 2017-11-28

Tracking down FNP A bootload fail

Received BOOTLOAD command for Idx 0 'fnp-a' mb 3400
DBG(267769323017)> IOM DEBUG: mbxLoc: IOM A, chan 17 is 000000001504^M
DBG(267769323017)> IOM DEBUG: SCW chan 21 376550000000^M
DBG(267769323017)> IOM DEBUG: status_service: Status tally 0 (0) lq 0^M
DBG(267769323017)> IOM DEBUG: status_service: Writing status for chan 17 dev_code 0 to 01506=>0376550^M
DBG(267769323017)> IOM TRACE: Writing status for chan 17 dev_code 0 to 01506=>0376550^M
DBG(267769323017)> IOM ALL: status_service: Status: 0400002000000 0000000040000^M
DBG(267769323017)> IOM NOTIFY: send_general_interrupt: IOM A, channel 17 (021), level 1; Interrupt 12 (014).^M
DBG(267769323017)> IOM DEBUG: send_general_interrupt: IMW at 01214 was 000000000000; setting bit 17^M
DBG(267769323017)> IOM INFO: send_general_interrupt: IMW at 01214 now 000001000000^M
DBG(267769323017)> IOM DEBUG: iom_interrupt: IOM A finished; doConnectChan returned 0.^M

DBG(267769323275)> CPU TRACE:     000100  4a  4 00030 0341 20    165            ldac      iom_mailbox$+iom_mailbox_seg.imw_array_word,x4^M
DBG(267769323275)> CPU REGDUMPAQI: A=000001000000 Q=000000000000 IR:~BAR ^M
DBG(267769323277)> CPU TRACE:     000101  aa   000064 6000 04    166            tze       null_int-*,ic       " no IMW bit set^M
DBG(267769323279)> CPU TRACE:     000102  aa   000000 2360 03    168            ldq       0,du                " make a fake float number^M
DBG(267769323281)> CPU TRACE:     000103  aa   000000 4110 03    169            lde       0,du^M
DBG(267769323283)> CPU TRACE:     000104  aa   000001 7730 00    170            lrl       1^M
DBG(267769323285)> CPU TRACE:     000105  aa   000003 7100 04    171            tra       imw_begin-*,ic      " start scanning^M
DBG(267769323287)> CPU TRACE:     000110                         179  imw_begin:^M
DBG(267769323287)> CPU TRACE:     000110  aa   000000 6340 07    180            ldi       0,dl                " clear hex and overflow bits^M
DBG(267769323289)> CPU TRACE:     000111  aa   000000 5730 00    181            fno^M
DBG(267769323291)> CPU TRACE:     000112  aa   200000 6750 03    182            era       =o200000,du         " clear the bit^M
DBG(267769323293)> CPU TRACE:     000113  aa  6 00062 4571 00    183            dfst      imw_save^M
DBG(267769323295)> CPU TRACE:     000114  aa  6 00062 2351 00    185            lda       imw_save            " get channel number^M
DBG(267769323295)> CPU REGDUMPAQI: A=736000000000 Q=000000000000 IR:~BAR Neg ^M
DBG(267769323297)> CPU TRACE:     000115  aa   000034 7310 00    186            ars       36-8                " in AL^M
DBG(267769323299)> CPU TRACE:     000116  aa   000000 5310 00    187            neg       0^M
DBG(267769323299)> CPU REGDUMPAQI: A=000000000021 Q=000000000000 IR:~BAR ^M
DBG(267769323301)> CPU TRACE:     000117  aa  6 00066 0751 00    188            ada       chantab_base        " add chantab offset^M
DBG(267769323301)> CPU CORE: core_read  77025306 000000000000 (OPERAND_READ)^M
DBG(267769323301)> CPU REGDUMPAQI: A=000000000021 Q=000000000000 IR:~BAR ^M
DBG(267769323303)> CPU TRACE:     000120  aa  6 00065 7551 00    189            sta       index               " store in case of error^M
DBG(267769323305)> CPU TRACE:     000121  aa  0 00100 1015 05    191            mrl       (pr,al),(pr),fill(0) " Reference the channel table.^M
DBG(267769323307)> CPU TRACE:     000124  aa  6 00050 3501 00    195            eppap     hlr_arglist^M
DBG(267769323309)> CPU TRACE:     000125  aa  6 00070 2361 00    197            ldq       chx                 " chx in QL^M
DBG(267769323311)> CPU TRACE:     000126  aa   000031 6000 04    198            tze       invalid_int-*,ic    " Ignore interrupt if channel not assigned.^M
DBG(267769323313)> CPU TRACE:     000127  aa   000050 4020 07    199            mpy       per_device_size,dl^M
DBG(267769323315)> CPU TRACE:     000130  aa   777730 6210 06    200            eax1      -per_device_size,ql " index into per_device^M
DBG(267769323317)> CPU TRACE:     000131  aa  2 00266 2351 11    202            lda       bp|iom_data.per_device+per_device.flags,x1^M
DBG(267769323319)> CPU TRACE:     000132  aa   400000 3150 03    204            cana      per_device.in_use,du^M
DBG(267769323321)> CPU TRACE:     000133  aa   000024 6000 04    205            tze       invalid_int-*,ic    " Return if no handler assigned.^M
DBG(267769323323)> CPU TRACE:     000134  aa  2 00267 2351 11    207            lda       bp|iom_data.per_device+per_device.index,x1^M
DBG(267769323325)> CPU TRACE:     000135  aa  6 00065 7551 00    208            sta       index               " save the handler's index^M
DBG(267769323327)> CPU TRACE:     000136  aa  6 00067 7411 00    209            stx1      device              " save per_device index for ext. call^M
DBG(267769323329)> CPU TRACE:     000137  4a  4 00032 6331 20    211            rccl      sys_info$clock_,*   " Get int_time now.^M
DBG(267769323331)> CPU TRACE:     000140  aa  6 00060 7571 00    212            staq      time                " And save it.^M
DBG(267769323333)> CPU TRACE:     000141  aa  2 00262 3521 31    214            short_call bp|iom_data.per_device+per_device.handler,x1*^M
DBG(267769323333)> CPU TRACE: 00034:002703 0 200262352131 (EPP2 PR2|262,1*) 000262 352(0) 0 0 1 11^M
DBG(267769323333)> CPU FINAL: Read2 (Actual) Read:  iefpFinalAddress=00376572  readData=000122000043^M
DBG(267769323333)> CPU FINAL: Read2 (Actual) Read:  iefpFinalAddress=00376573  readData=000542000000^M

122:542

bound_355_wired                   122  (0, 0, 0) read execute encacheable wired
dn355                                0   7454      0      0    100    460

dn355$interrupt:

       61 interrupt:
       62      entry (x_dno, x_level, x_status);                      /* entry from iom_manager */
       63
       64 dcl  x_dno fixed bin (35);                                  /* index from assignment time */
       65 dcl  x_level fixed bin (3);                                 /* interrupt level */
       66 dcl  x_status bit (36) aligned;                             /* status after special or fault */
       67
       68           if tc_data$system_shutdown ^= 0
       69           then return;                                      /* ignore 355's if shut down in progress */
       70           interrupt_entry = "1"b;
       71
       72           call setup;
       73           level = x_level;                                  /* copy level to local stack */
       74           if datanet_info.trace
       75           then do;

....

       83           if level ^= 3 & level ^= 7
       84           then do;                                          /* if not a good interrupt level */

....

       92           if (^fnp_info.t_and_d_in_progress) & (^fnp_info.running) & (^fnp_info.bootloading)
       93           then return;                                      /* spurious interrupt */
       94
       95           if ^stac (addr (lcte.lock), pds$processid)        /* somebody else has it */
       96           then do;
       97
       98                do while (^stac (addr (fnp_info.queue_lock), pds$processid));
       99                end;
      100
      101                if level = 7
      102                then fnp_info.level_7_pending = "1"b;
      103                else fnp_info.level_3_pending = "1"b;
      104
      105                if stac (addr (lcte.lock), pds$processid)    /* in case it got unlocked meanwhile */
      106                then call process_int_queue ("0"b);
      107
      108                else if ^stacq (fnp_info.queue_lock, "0"b, pds$processid)
      109                then call syserr (crash_system, "dn355: inconsistent queue lock");
      110           end;

...

      121           return;

DBG(138255425)> CPU TRACE:        61 interrupt:^M
DBG(138255425)> CPU TRACE: 00122:000542 0 001520627000 (EAX7 001520) 001520 627(0) 0 0 0 00^M
DBG(138255427)> CPU TRACE: 00122:000543 0 700034352120 (EPP2 PR7|34,N*) 000034 352(0) 0 0 1 00^M
DBG(138255429)> CPU TRACE: 00122:000544 0 201045272100 (TSP2 PR2|1045) 001045 272(0) 0 0 0 00^M
DBG(138255473)> CPU TRACE: 00122:000547 0 600044370120 (EPP4 PR6|44,N*) 000044 370(0) 0 0 1 00^M

DBG(138255475)> CPU TRACE:        68    if tc_data$system_shutdown ^= 0^M
DBG(138255475)> CPU TRACE: 00122:000550 0 400214236120 (LDQ PR4|214,N*) 000214 236(0) 0 0 1 00^M
DBG(138255477)> CPU TRACE: 00122:000551 0 000631601100 (TNZ PR0|631) 000631 601(0) 0 0 0 00^M

DBG(138255479)> CPU TRACE:        70    interrupt_entry = "1"b;^M
DBG(138255479)> CPU TRACE: 00122:000552 0 400000235003 (LDA 400000,DU) 400000 235(0) 0 0 0 03^M
DBG(138255481)> CPU TRACE: 00122:000553 0 600141755100 (STA PR6|141) 000141 755(0) 0 0 0 00^M

DBG(138255483)> CPU TRACE:        72    call setup;^M
DBG(138255483)> CPU TRACE: 00122:000554 0 000710670004 (TSP4 000710,IC) 000710 670(0) 0 0 0 04^M

DBG(138255485)> CPU TRACE:       246 setup:^M
DBG(138255485)> CPU TRACE: 00122:001464 0 600306650100 (SPRI4 PR6|306) 000306 650(0) 0 0 0 00^M

DBG(138255487)> CPU TRACE:       249    ttybp = addr (tty_buf$);                          /* get addr of tty buffer segment */^M
DBG(138255487)> CPU TRACE: 00122:001465 0 600044370120 (EPP4 PR6|44,N*) 000044 370(0) 0 0 1 00^M
DBG(138255489)> CPU TRACE: 00122:001466 0 400224373520 (EPP7 PR4|224,N*) 000224 373(1) 0 0 1 00^M
DBG(138255491)> CPU TRACE: 00122:001467 0 600272653500 (SPRI7 PR6|272) 000272 653(1) 0 0 0 00^M

DBG(138255493)> CPU TRACE:       250    dno = x_dno;                                      /* copy 355 number to local stack */^M
DBG(138255493)> CPU TRACE: 00122:001470 0 600032371520 (EPP5 PR6|32,N*) 000032 371(1) 0 0 1 00^M
DBG(138255495)> CPU TRACE: 00122:001471 0 500002236120 (LDQ PR5|2,N*) 000002 236(0) 0 0 1 00^M
DBG(138255497)> CPU TRACE: 00122:001472 0 600122756100 (STQ PR6|122) 000122 756(0) 0 0 0 00^M

DBG(138255499)> CPU TRACE:       251    infop = addr (dn355_data$);                       /* get address of 355 info segment */^M
DBG(138255499)> CPU TRACE: 00122:001473 0 400226353520 (EPP3 PR4|226,N*) 000226 353(1) 0 0 1 00^M
DBG(138255501)> CPU TRACE: 00122:001474 0 600236253500 (SPRI3 PR6|236) 000236 253(1) 0 0 0 00^M

DBG(138255503)> CPU TRACE:       253    fnpp = addr (datanet_info.per_datanet (dno));^M
DBG(138255503)> CPU TRACE: 00122:001475 0 000072402007 (MPY 000072,DL) 000072 402(0) 0 0 0 07^M
DBG(138255505)> CPU TRACE: 00122:001476 0 377730351506 (EPP1 PR3|77730,QL) 777730 351(1) 0 0 0 06^M
DBG(138255507)> CPU TRACE: 00122:001477 0 600240251500 (SPRI1 PR6|240) 000240 251(1) 0 0 0 00^M

DBG(138255509)> CPU TRACE:       254    fnp_name = fnp_info.fnp_tag;^M
DBG(138255509)> CPU TRACE: 00122:001500 0 100007235100 (LDA PR1|7) 000007 235(0) 0 0 0 00^M
DBG(138255511)> CPU TRACE: 00122:001501 0 000022377100 (ANAQ PR0|22) 000022 377(0) 0 0 0 00^M
DBG(138255513)> CPU TRACE: 00122:001502 0 600137755100 (STA PR6|137) 000137 755(0) 0 0 0 00^M

DBG(138255515)> CPU TRACE:       255    mbxp = fnp_info.mbx_pt;                           /* get mailbox pointer */^M
DBG(138255515)> CPU TRACE: 00122:001503 0 100000373520 (EPP7 PR1|0,N*) 000000 373(1) 0 0 1 00^M
DBG(138255517)> CPU TRACE: 00122:001504 0 600244653500 (SPRI7 PR6|244) 000244 653(1) 0 0 0 00^M

DBG(138255519)> CPU TRACE:       256    lctep = fnp_info.lcte_ptr;^M
DBG(138255519)> CPU TRACE: 00122:001505 0 100032353520 (EPP3 PR1|32,N*) 000032 353(1) 0 0 1 00^M
DBG(138255521)> CPU TRACE: 00122:001506 0 600254253500 (SPRI3 PR6|254) 000254 253(1) 0 0 0 00^M

DBG(138255523)> CPU TRACE:       258    return;^M
DBG(138255523)> CPU TRACE: 00122:001507 0 600306610100 (RTCD PR6|306) 000306 610(0) 0 0 0 00^M

DBG(138255525)> CPU TRACE:        73    level = x_level;                                  /* copy level to local stack */^M
DBG(138255525)> CPU TRACE: 00122:000555 0 600032373520 (EPP7 PR6|32,N*) 000032 373(1) 0 0 1 00^M
DBG(138255527)> CPU TRACE: 00122:000556 0 700004236120 (LDQ PR7|4,N*) 000004 236(0) 0 0 1 00^M
DBG(138255529)> CPU TRACE: 00122:000557 0 600121756100 (STQ PR6|121) 000121 756(0) 0 0 0 00^M

DBG(138255531)> CPU TRACE:        74    if datanet_info.trace^M
DBG(138255531)> CPU TRACE: 00122:000560 0 600236371520 (EPP5 PR6|236,N*) 000236 371(1) 0 0 1 00^M
DBG(138255533)> CPU TRACE: 00122:000561 0 500005235100 (LDA PR5|5) 000005 235(0) 0 0 0 00^M
DBG(138255535)> CPU TRACE: 00122:000562 0 000071600004 (TZE 000071,IC) 000071 600(0) 0 0 0 04^M

DBG(138255537)> CPU TRACE:        83    if level ^= 3 & level ^= 7^M
DBG(138255537)> CPU TRACE: 00122:000653 0 600121236100 (LDQ PR6|121) 000121 236(0) 0 0 0 00^M
DBG(138255539)> CPU TRACE: 00122:000654 0 000003116007 (CMPQ 000003,DL) 000003 116(0) 0 0 0 07^M
DBG(138255541)> CPU TRACE: 00122:000655 0 000051600004 (TZE 000051,IC) 000051 600(0) 0 0 0 04^M

DBG(138255543)> CPU TRACE:        92    if (^fnp_info.t_and_d_in_progress) & (^fnp_info.running) & (^fnp_info.bootloading)^M
DBG(138255543)> CPU TRACE: 00122:000726 0 600240373520 (EPP7 PR6|240,N*) 000240 373(1) 0 0 1 00^M
DBG(138255545)> CPU TRACE: 00122:000727 0 700030235100 (LDA PR7|30) 000030 235(0) 0 0 0 00^M
DBG(138255547)> CPU TRACE: 00122:000730 0 301000315003 (CANA 301000,DU) 301000 315(0) 0 0 0 03^M
DBG(138255549)> CPU TRACE: 00122:000731 0 000631600100 (TZE PR0|631) 000631 600(0) 0 0 0 00^M

DBG(138255551)> CPU TRACE:        95    if ^stac (addr (lcte.lock), pds$processid)        /* somebody else has it */^M
DBG(138255551)> CPU TRACE: 00122:000732 0 600254371520 (EPP5 PR6|254,N*) 000254 371(1) 0 0 1 00^M
DBG(138255553)> CPU TRACE: 00122:000733 0 600620651500 (SPRI5 PR6|620) 000620 651(1) 0 0 0 00^M
DBG(138255555)> CPU TRACE: 00122:000734 0 600044370120 (EPP4 PR6|44,N*) 000044 370(0) 0 0 1 00^M
DBG(138255557)> CPU TRACE: 00122:000735 0 400220235120 (LDA PR4|220,N*) 000220 235(0) 0 0 1 00^M
DBG(138255559)> CPU TRACE: 00122:000736 0 500000352100 (EPP2 PR5|0) 000000 352(0) 0 0 0 00^M
DBG(138255561)> CPU TRACE: 00122:000737 0 000663700100 (TSX0 PR0|663) 000663 700(0) 0 0 0 00^M
DBG(138255573)> CPU TRACE: 00122:000740 0 000066601004 (TNZ 000066,IC) 000066 601(0) 0 0 0 04^M

BG(138255575)> CPU TRACE:        98         do while (^stac (addr (fnp_info.queue_lock), pds$processid));^M
DBG(138255575)> CPU TRACE: 00122:000741 0 000000011003 (NOP 000000,DU) 000000 011(0) 0 0 0 03^M
DBG(138255577)> CPU TRACE: 00122:000742 0 600240373520 (EPP7 PR6|240,N*) 000240 373(1) 0 0 1 00^M
DBG(138255579)> CPU TRACE: 00122:000743 0 700043373500 (EPP7 PR7|43) 000043 373(1) 0 0 0 00^M
DBG(138255581)> CPU TRACE: 00122:000744 0 600622653500 (SPRI7 PR6|622) 000622 653(1) 0 0 0 00^M
DBG(138255583)> CPU TRACE: 00122:000745 0 600044370120 (EPP4 PR6|44,N*) 000044 370(0) 0 0 1 00^M
DBG(138255585)> CPU TRACE: 00122:000746 0 400220235120 (LDA PR4|220,N*) 000220 235(0) 0 0 1 00^M
DBG(138255587)> CPU TRACE: 00122:000747 0 700000352100 (EPP2 PR7|0) 000000 352(0) 0 0 0 00^M
DBG(138255589)> CPU TRACE: 00122:000750 0 000663700100 (TSX0 PR0|663) 000663 700(0) 0 0 0 00^M
DBG(138255601)> CPU TRACE: 00122:000751 0 000002601004 (TNZ 000002,IC) 000002 601(0) 0 0 0 04^M

DBG(138255603)> CPU TRACE:       101         if level = 7^M
DBG(138255603)> CPU TRACE: 00122:000753 0 600121236100 (LDQ PR6|121) 000121 236(0) 0 0 0 00^M
DBG(138255603)> CPU REGDUMPAQI: A=400000000000 Q=000000000003 IR:~BAR Carry ^M
DBG(138255605)> CPU TRACE: 00122:000754 0 000007116007 (CMPQ 000007,DL) 000007 116(0) 0 0 0 07^M
DBG(138255607)> CPU TRACE: 00122:000755 0 000005601004 (TNZ 000005,IC) 000005 601(0) 0 0 0 04^M

DBG(138255609)> CPU TRACE:       103         else fnp_info.level_3_pending = "1"b;^M
DBG(138255609)> CPU TRACE: 00122:000762 0 010000235003 (LDA 010000,DU) 010000 235(0) 0 0 0 03^M
DBG(138255611)> CPU TRACE: 00122:000763 0 600240371520 (EPP5 PR6|240,N*) 000240 371(1) 0 0 1 00^M
DBG(138255613)> CPU TRACE: 00122:000764 0 500030255100 (ORSA PR5|30) 000030 255(0) 0 0 0 00^M

DBG(138255615)> CPU TRACE:       105         if stac (addr (lcte.lock), pds$processid)    /* in case it got unlocked meanwhile */^M
DBG(138255615)> CPU TRACE: 00122:000765 0 600254353520 (EPP3 PR6|254,N*) 000254 353(1) 0 0 1 00^M
DBG(138255617)> CPU TRACE: 00122:000766 0 600624253500 (SPRI3 PR6|624) 000624 253(1) 0 0 0 00^M
DBG(138255619)> CPU TRACE: 00122:000767 0 400220235120 (LDA PR4|220,N*) 000220 235(0) 0 0 1 00^M
DBG(138255621)> CPU TRACE: 00122:000770 0 300000352100 (EPP2 PR3|0) 000000 352(0) 0 0 0 00^M
DBG(138255623)> CPU TRACE: 00122:000771 0 000663700100 (TSX0 PR0|663) 000663 700(0) 0 0 0 00^M
DBG(138255635)> CPU TRACE: 00122:000772 0 000006600004 (TZE 000006,IC) 000006 600(0) 0 0 0 04^M

DBG(138255637)> CPU TRACE:       108         else if ^stacq (fnp_info.queue_lock, "0"b, pds$processid)^M
DBG(138255637)> CPU TRACE: 00122:001000 0 000000235007 (LDA 000000,DL) 000000 235(0) 0 0 0 07^M
DBG(138255639)> CPU TRACE: 00122:001001 0 600240371520 (EPP5 PR6|240,N*) 000240 371(1) 0 0 1 00^M
DBG(138255641)> CPU TRACE: 00122:001002 0 500043352100 (EPP2 PR5|43) 000043 352(0) 0 0 0 00^M
DBG(138255643)> CPU TRACE: 00122:001003 0 400220236120 (LDQ PR4|220,N*) 000220 236(0) 0 0 1 00^M
DBG(138255645)> CPU TRACE: 00122:001004 0 001434700100 (TSX0 PR0|1434) 001434 700(0) 0 0 0 00^M
DBG(138255657)> CPU TRACE: 00122:001005 0 000040601004 (TNZ 000040,IC) 000040 601(0) 0 0 0 04^M
DBG(138255659)> CPU TRACE:       121    return;^M
DBG(138255659)> CPU TRACE: 00122:001045 0 000631710100 (TRA PR0|631) 000631 710(0) 0 0 0 00^M
Unless otherwise stated, the content of this page is licensed under Creative Commons Attribution-ShareAlike 3.0 License