vwemirror/TeslaRel410
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity
Files
475ae3106e6e503b5d8764bae8421a8dc18f4569
TeslaRel410/emulator/render-bridge/podlog.txt
T
CydandClaude Fable 5 475ae3106e BT410 5.3.59: A MISSION RUNS -- the RIO serial port was blocking every load 
pod_render_norio.conf is pod_render_rec.conf with one line changed,
serial1=disabled instead of the vrio named pipe.  Same binary, same egg.  With
it, our build launches and the mech walks:

  [launch] state=2 minPriorityEmpty=1 ticks=85316
  [queues] p0=- p1=- p2=BUSY p3=- p4=-
  BTL4Application::RunMissionMessageHandler
  Turning Plasma Score Display On
  [sim] pos=(180.466,10,-358.703) yaw=-0.275605 spd=14.4
  [sim] pos=(251.959,10,-250.498) yaw=-0.89103  spd=14.4

No fault, 290 log lines and counting.  This is the first time the
reconstruction has reached a running mission on the pod.

The hang was never starvation, a deadlock, or a refill loop -- it was VOLUME,
the first candidate I listed and then talked myself out of.  530 renderer
events queue at priority 0 during load; BackgroundTasks::Execute runs exactly
one task per call round-robin over seven tasks, and the 1ms frame budget is
always blown here so no extra background passes happen.  That is ~9 events per
real second, so a load legitimately takes ~60s.  The fault arrived at ~40s,
before the backlog could clear.  Every 'the queue never drains' reading was
really 'the process dies before it can'.

The disproof was already in hand: the post tally climbed to 530 and went FLAT,
which means nothing was refilling.  p0=BUSY with nextReady=1 is equally
consistent with a large finite backlog still draining, and I read it as refill.

Why the RIO port: the pipe has no server attached, which should behave as an
unplugged cable.  The emulator log shows steady serial1 RX overruns, our build
prints 'RIO never came back from test mode!', and the SHIPPED binary prints
'lost RIO analog request' and launches anyway on this identical rig.  So an
unplugged RIO is survivable and our handling of it is not -- a real defect, not
a rig artifact, since a pod with an unplugged RIO cable should still boot.

The wild reference at EulerAngles::operator=(const LinearMatrix&)+0x19 is still
unexplained, but it is now reproducible on demand by enabling serial1 rather
than being a coin flip.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-28 23:23:29 -05:00

291 lines
14 KiB
Plaintext
Raw Blame History

BattleTech v4.10
BTL4Application::BTL4Application
RIO never came back from check request!
GaugeInterpreter: undefined label 'Initialization'
[exp] master player experience=2 simLive=1 heatModelOn=1 advDamage=1
[role] 'Role::Default' lives=1000 killBonus=500 dmgMod=1
[torso] horizJoint 'jointtorso' -> 0x00a3d170 type=1 enabled=1
[weap] 'AFC100' seg=13 mount=sitelgunport rear=0
[proj] 'AFC100' ammoBinIndex=21 -> AmmoBinAFC100 (rounds=20)
[weap] 'ERLLaser' seg=7 mount=siterugunport rear=0
[weap] 'ERSLaser_1' seg=13 mount=sitelgunport rear=0
[weap] 'ERSLaser_2' seg=8 mount=siterdgunport rear=0
[weap] 'LRM15_1' seg=18 mount=sitelmissleport rear=0
[proj] 'LRM15_1' ammoBinIndex=26 -> AmmoBinLRM15_1 (rounds=16)
[weap] 'LRM15_2' seg=19 mount=sitermissleport rear=0
[proj] 'LRM15_2' ammoBinIndex=28 -> AmmoBinLRM15_2 (rounds=16)
[mech] segment walk done: subsystemCount=32 weaponCount=6
[skel] jointSubsystem=0x009e6d84 jointCount=25
[mech] model params: walkTR=65 runTR=40 maxAcc=20 throttleAdj=0.8 (deg,deg,u/s^2,scale)
[mech] look angles: L=50 R=-50 F=-15 B=0 (deg)
[mech] damage zones streamed: 22 [dz_dtorso,dz_hip,dz_larm,dz_ldleg,dz_ldoor,dz_lfoot,dz_lgun,dz_ltorso,dz_luleg,dz_rarm,dz_rdleg,dz_rdoor,dz_reardtorso,dz_rearltorso,dz_rearrtorso,dz_rearutorso,dz_rfoot,dz_rgun,dz_rtorso,dz_ruleg,dz_searchlight,dz_utorso]
[cyl] table 'madcat' LOADED rows=7
[valve] 'Condenser1' valve=1 flow=0.166667
[valve] 'Condenser2' valve=1 flow=0.166667
[valve] 'Condenser3' valve=1 flow=0.166667
[valve] 'Condenser4' valve=1 flow=0.166667
[valve] 'Condenser5' valve=1 flow=0.166667
[valve] 'Condenser6' valve=1 flow=0.166667
[mapper] ctor id=0 throttleAttr=0x009f4320 controlModeAttr=0x009f435c
[gau2] cluster slot=14 classID=3011 auxScreen=5 name=Avionics
[gau2] cluster slot=15 classID=3014 auxScreen=6 name=Myomers
[gau2] cluster slot=22 classID=3021 auxScreen=1 name=AFC100
[gau2] cluster slot=23 classID=3016 auxScreen=10 name=ERLLaser
[gau2] cluster slot=24 classID=3016 auxScreen=3 name=ERSLaser_1
[gau2] cluster slot=25 classID=3016 auxScreen=12 name=ERSLaser_2
[gau2] cluster slot=27 classID=3024 auxScreen=2 name=LRM15_1
[gau2] cluster slot=29 classID=3024 auxScreen=9 name=LRM15_2
ColorMapperArmor warning: damage zone dz_missle not found
ColorMapperArmor warning: damage zone dz_missle not found
ColorMapperArmor warning: damage zone dz_lmissle not found
ColorMapperArmor warning: damage zone dz_rmissle not found
ColorMapperArmor warning: damage zone dz_ftorso not found
ColorMapperArmor warning: damage zone dz_btorso not found
[link] InitializePlayerLink -> vehicle playerLink=0x00ac513c
[launch] state=11 minPriorityEmpty=0 ticks=14713
[queues] p0=BUSY p1=BUSY p2=BUSY p3=BUSY p4=- nextReady=1
[posts] id3=416
[launch] state=11 minPriorityEmpty=0 ticks=15726
[queues] p0=BUSY p1=BUSY p2=BUSY p3=BUSY p4=- nextReady=1
[posts] id3=502
[launch] state=11 minPriorityEmpty=0 ticks=16736
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=11 minPriorityEmpty=0 ticks=17745
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=11 minPriorityEmpty=0 ticks=18754
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=19831
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=20940
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=22051
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=23160
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=24269
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=25380
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=26489
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=27598
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[stack] frame at 0x12dee7 drift=0 over 1001 frames ticks=28077 pump=352/1499
[launch] state=2 minPriorityEmpty=0 ticks=28710
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=29819
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
LBE4ControlsManager::Execute, lost RIO analog request
iThinkIRQIsOn =1, actual state =1, characters sent =40
[launch] state=2 minPriorityEmpty=0 ticks=30929
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=32040
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=33149
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=34258
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=35369
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=36478
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=37587
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=38700
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=39809
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=40918
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=42029
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=43138
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[stack] frame at 0x12dee7 drift=0 over 2002 frames ticks=43949 pump=495/2643
[launch] state=2 minPriorityEmpty=0 ticks=44248
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[skl] video\mad.skl -> 26 nodes, 19 objects
LBE4ControlsManager::Execute, lost RIO analog request
iThinkIRQIsOn =1, actual state =1, characters sent =41
[launch] state=2 minPriorityEmpty=0 ticks=45360
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=46469
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=47578
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=48689
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=49798
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=50907
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=52018
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=53127
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=54236
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=55349
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=56458
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=57567
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=58678
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=59787
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[stack] frame at 0x12dee7 drift=0 over 3003 frames ticks=59824 pump=638/3787
LBE4ControlsManager::Execute, lost RIO analog request
iThinkIRQIsOn =1, actual state =1, characters sent =42
[launch] state=2 minPriorityEmpty=0 ticks=60898
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=62009
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=63118
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=64227
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=65338
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=66447
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=67556
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=68667
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=69776
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=70885
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=71996
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=73107
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=74216
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
LBE4ControlsManager::Execute, lost RIO analog request
iThinkIRQIsOn =1, actual state =1, characters sent =43
[launch] state=2 minPriorityEmpty=0 ticks=75328
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[stack] frame at 0x12dee7 drift=0 over 4004 frames ticks=75695 pump=781/4931
[launch] state=2 minPriorityEmpty=0 ticks=76438
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=77547
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=78658
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=79767
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
MapDisplay: operating=1 static=7 moving=0
[launch] state=2 minPriorityEmpty=0 ticks=80876
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=81987
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=83096
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=0 ticks=84205
[queues] p0=BUSY p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
[launch] state=2 minPriorityEmpty=1 ticks=85316
[queues] p0=- p1=- p2=BUSY p3=- p4=- nextReady=1
[posts] id3=530
BTL4Application::RunMissionMessageHandler
Turning Plasma Score Display On
BTL4Application::RunMissionMessageHandler
Turning Plasma Score Display On
[tick] roster live (first Sensor frame), radarPercent=1 voltState=4
[mppr] thr=0.6 rev=0 stickX=0.25 stickY=0 mode=0 -> speedDemand=14.4 turnDemand=0.0625 torsoElev=0
[sim] pos=(172.94,10,-401.227) yaw=-0.0736139 spd=14.4 eyePitch=0 eyeYaw=0
[fire] 'ERSLaser_1' LOADED (level=7941.22 T=76.8855)
[fire] 'ERSLaser_2' LOADED (level=7925.96 T=76.8462)
LBE4ControlsManager::Execute, lost RIO analog request
iThinkIRQIsOn =1, actual state =1, characters sent =48
[mppr] thr=0.6 rev=0 stickX=0.25 stickY=0 mode=0 -> speedDemand=14.4 turnDemand=0.0625 torsoElev=0
[sim] pos=(174.491,10,-386.899) yaw=-0.140905 spd=14.4 eyePitch=0 eyeYaw=0
[mppr] thr=0.6 rev=0 stickX=0.25 stickY=0 mode=0 -> speedDemand=14.4 turnDemand=0.0625 torsoElev=0
[sim] pos=(177.005,10,-372.693) yaw=-0.208286 spd=14.4 eyePitch=0 eyeYaw=0
[stack] frame at 0x12dee7 drift=0 over 5005 frames ticks=91705 pump=863/6075
[mppr] thr=0.6 rev=0 stickX=0.25 stickY=0 mode=0 -> speedDemand=14.4 turnDemand=0.0625 torsoElev=0
[sim] pos=(180.466,10,-358.703) yaw=-0.275605 spd=14.4 eyePitch=0 eyeYaw=0
[mppr] thr=0.6 rev=0 stickX=0.25 stickY=0 mode=0 -> speedDemand=14.4 turnDemand=0.0625 torsoElev=0
[sim] pos=(184.942,10,-344.747) yaw=-0.344067 spd=14.4 eyePitch=0 eyeYaw=0
[fire] 'ERLLaser' LOADED (level=7928.31 T=76.0943)
[mppr] thr=0.6 rev=0 stickX=0.25 stickY=0 mode=0 -> speedDemand=14.4 turnDemand=0.0625 torsoElev=0
[sim] pos=(190.352,10,-331.157) yaw=-0.412398 spd=14.4 eyePitch=0 eyeYaw=0
[mppr] thr=0.6 rev=0 stickX=0.25 stickY=0 mode=0 -> speedDemand=14.4 turnDemand=0.0625 torsoElev=0
[sim] pos=(196.676,10,-317.967) yaw=-0.480733 spd=14.4 eyePitch=0 eyeYaw=0
[mppr] thr=0.6 rev=0 stickX=0.25 stickY=0 mode=0 -> speedDemand=14.4 turnDemand=0.0625 torsoElev=0
[sim] pos=(203.902,10,-305.216) yaw=-0.549203 spd=14.4 eyePitch=0 eyeYaw=0
[mppr] thr=0.6 rev=0 stickX=0.25 stickY=0 mode=0 -> speedDemand=14.4 turnDemand=0.0625 torsoElev=0
[sim] pos=(211.966,10,-293.012) yaw=-0.61754 spd=14.4 eyePitch=0 eyeYaw=0
[mppr] thr=0.6 rev=0 stickX=0.25 stickY=0 mode=0 -> speedDemand=14.4 turnDemand=0.0625 torsoElev=0
[sim] pos=(220.845,10,-281.387) yaw=-0.685878 spd=14.4 eyePitch=0 eyeYaw=0
[mppr] thr=0.6 rev=0 stickX=0.25 stickY=0 mode=0 -> speedDemand=14.4 turnDemand=0.0625 torsoElev=0
[sim] pos=(230.517,10,-270.375) yaw=-0.754352 spd=14.4 eyePitch=0 eyeYaw=0
[mppr] thr=0.6 rev=0 stickX=0.25 stickY=0 mode=0 -> speedDemand=14.4 turnDemand=0.0625 torsoElev=0
[sim] pos=(240.898,10,-260.07) yaw=-0.822691 spd=14.4 eyePitch=0 eyeYaw=0
[mppr] thr=0.6 rev=0 stickX=0.25 stickY=0 mode=0 -> speedDemand=14.4 turnDemand=0.0625 torsoElev=0
[sim] pos=(251.959,10,-250.498) yaw=-0.89103 spd=14.4 eyePitch=0 eyeYaw=0
Reference in New Issue View Git Blame Copy Permalink