Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Can't load alternate missions #20

Closed
btb opened this issue Dec 7, 2014 · 32 comments
Closed

Can't load alternate missions #20

btb opened this issue Dec 7, 2014 · 32 comments
Assignees
Milestone

Comments

@btb
Copy link
Contributor

btb commented Dec 7, 2014

fea751b breaks handling of alternate missions for me. Playing the builtin mission works fine, as long as there are no alternate missions available (i.e. the mission menu never pops up)

f1a6278 fixes it, by just reverting the meat of that commit. I honestly can't even parse this modern new-fangled C++ well enough to know how to fix it otherwise.

* thread #1: tid = 0x33271, 0x000000010015ff3d d2x-rebirth`set_briefing_filename(d_fname&, char const*) [inlined] char const* std::__1::find<char const*, char>(__first=0x0000c17efd0fd209, __last=0x0000c17efd0fd211, __value_=0x00007fff5fbfbf57) + 27 at algorithm:846, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=EXC_I386_GPFLT)
    frame #0: 0x000000010015ff3d d2x-rebirth`set_briefing_filename(d_fname&, char const*) [inlined] char const* std::__1::find<char const*, char>(__first=0x0000c17efd0fd209, __last=0x0000c17efd0fd211, __value_=0x00007fff5fbfbf57) + 27 at algorithm:846
  * frame #1: 0x000000010015ff22 d2x-rebirth`set_briefing_filename(f=0x0000610000101510, v=0x0000c17efd0fd209) + 258 at mission.cpp:684
    frame #2: 0x0000000100159e26 d2x-rebirth`load_mission(mission=0x0000000103105a48) + 6246 at mission.cpp:800
    frame #3: 0x000000010015ccb5 d2x-rebirth`mission_menu_handler(lb=0x00006080000e3000, event=0x00007fff5fbfe3a0, mm=0x0000608000023620) + 197 at mission.cpp:966
    frame #4: 0x00000001001a00b4 d2x-rebirth`listbox_key_command(wind=0x00006080000e0780, event=0x00007fff5fbfe4f8, lb=0x00006080000e3000) + 516 at newmenu.cpp:1823
    frame #5: 0x000000010019f8c5 d2x-rebirth`listbox_handler(wind=0x00006080000e0780, event=0x00007fff5fbfe4f8, lb=0x00006080000e3000) + 325 at newmenu.cpp:2026
    frame #6: 0x0000000100014345 d2x-rebirth`window_send_event(wind=0x00006080000e0780, event=0x00007fff5fbfe4f8) + 53 at window.cpp:208
    frame #7: 0x0000000100052e9d d2x-rebirth`event_send(event=0x00007fff5fbfe4f8) + 109 at event.cpp:132
    frame #8: 0x0000000100053ee5 d2x-rebirth`key_handler(kevent=0x00007fff5fbfe810) + 2245 at key.cpp:434
    frame #9: 0x0000000100052ca9 d2x-rebirth`event_poll() + 329 at event.cpp:45
    frame #10: 0x0000000100052fbb d2x-rebirth`event_process() + 27 at event.cpp:154
    frame #11: 0x000000010012c871 d2x-rebirth`SDL_main(argc=3, argv=0x00006000000232a0) + 1729 at inferno.cpp:547
@vLKp vLKp self-assigned this Dec 7, 2014
@vLKp
Copy link
Contributor

vLKp commented Dec 8, 2014

Alternate missions work fine here. I usually have more than a dozen mn2 files listed. When you say it breaks handling of alternate missions, do you mean that the game crashes with that callstack? What is the output of info locals and info args in each of the three innermost frames? What is the value of f.size() and sizeof(tex) in set_briefing_filename?

@btb
Copy link
Contributor Author

btb commented Dec 8, 2014

yes, it crashes there, when I try to start the Vertigo mission.
here's (the lldb equivalent for) everything except f.size(), which I don't know how to get.

(lldb) frame select 0
frame #0: 0x000000010015fc6d d2x-rebirth`set_briefing_filename(d_fname&, char const*) [inlined] char const* std::__1::find<char const*, char>(__first=0x0000c0fefd4f61a9, __last=0x0000c0fefd4f61b1, __value_=0x00007fff5fbfbf57) + 27 at algorithm:846
   843  find(_InputIterator __first, _InputIterator __last, const _Tp& __value_)
   844  {
   845      for (; __first != __last; ++__first)
-> 846          if (*__first == __value_)
   847              break;
   848      return __first;
   849  }
(lldb) frame variable
(const unsigned char *) __first = 0x0000c0fefd4f61a9 ""
(const unsigned char *) __last = 0x0000c0fefd4f61b1 ""
(const unsigned char &) __value_ = 0x00007fff5fbfbf57: {
  &__value_ = '.'
}
(lldb) up
frame #1: 0x000000010015fc52 d2x-rebirth`set_briefing_filename(f=0x00006080001035b0, v=0x0000c0fefd4f61a9) + 258 at mission.cpp:684
   681      using std::copy;
   682      using std::next;
   683      auto &tex = ".tex";
-> 684      auto o = copy(v, std::find(v, next(v, f.size() - sizeof(tex)), '.'), begin(f));
   685      copy(begin(tex), end(tex), o);
   686      auto &txb = "txb";
   687      if (!PHYSFSX_exists(static_cast<const char *>(f), 1) && !(copy(begin(txb), end(txb), next(o)), PHYSFSX_exists(static_cast<const char *>(f), 1))) // check if this file exists ...
(lldb) frame variable
(d_fname &) f = 0x00006080001035b0: {
  std::__1::array<unsigned char, 13> = {
    __elems_ = ([0] = '\0', [1] = '\0', [2] = '\0', [3] = '\0', [4] = '\0', [5] = '\0', [6] = '\0', [7] = '\0', [8] = '\0', [9] = '\0', [10] = '\0', [11] = '\0', [12] = '\0')
  }
}
(const unsigned char *const) v = 0x0000c0fefd4f61a9 ""
(unsigned char const (&)[5]) tex = 0x00000001002794d9: {
  [0] = '.'
  [1] = 't'
  [2] = 'e'
  [3] = 'x'
  [4] = '\0'
}
(unsigned char *) o = 0x0000000000000000
(unsigned char const (&)[4]) txb = 0x0000000000000000
(lldb) p sizeof(tex)
(unsigned long) $0 = 5
(lldb) up
frame #2: 0x0000000100159b3a d2x-rebirth`load_mission(mission=0x0000000102d109a8) + 6250 at mission.cpp:800
   797          PHYSFSEXT_locateCorrectCase(buf);
   798          if (PHYSFSX_exists(buf,1))
   799              PHYSFSX_contfile_init(buf, 0);
-> 800          set_briefing_filename(Briefing_text_filename, Current_mission_filename);
   801          Ending_text_filename = Briefing_text_filename;
   802      }
   803  
(lldb) frame variable
(const mle *) mission = 0x0000000102d109a8
(PHYSFS_File *) mfile = 0x0000608000075940
(unsigned char [1024]) buf = "missions/d2x.hog"
(unsigned char *) v = 0x0000000000000000
(unsigned char const (&)[5]) msn_extension = 0x0000000100279378: {
  [0] = '.'
  [1] = 'm'
  [2] = 'n'
  [3] = '2'
  [4] = '\0'
}
(lldb) up
frame #3: 0x000000010015c9d5 d2x-rebirth`mission_menu_handler(lb=0x00006100000e2a00, event=0x00007fff5fbfe3a0, mm=0x0000610000025260) + 197 at mission.cpp:966
   963                  // Chose a mission
   964                  strcpy(GameCfg.LastMission, list[citem]);
   965                  
-> 966                  if (!load_mission(&mm->ml[citem]))
   967                  {
   968                      nm_messagebox( NULL, 1, TXT_OK, TXT_MISSION_ERROR);
   969                      return 1;   // stay in listbox so user can select another one
(lldb) frame variable
(listbox *) lb = 0x00006100000e2a00
(const d_event &) event = 0x00007fff5fbfe3a0: {
  type = EVENT_NEWMENU_SELECTED
}
(mission_menu *) mm = 0x0000610000025260
(const unsigned char **) list = 0x00006100000254e0
(int) citem = 1

@btb
Copy link
Contributor Author

btb commented Dec 8, 2014

Here's where it crashes when I start the built-in mission:

(lldb) bt
* thread #1: tid = 0x51660, 0x000000010001da33 d2x-rebirth`d_stricmp(s1=0x0000000100d800da, s2=0x0000c0fefd15cb79) + 35 at strutil.cpp:66, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=EXC_I386_GPFLT)
  * frame #0: 0x000000010001da33 d2x-rebirth`d_stricmp(s1=0x0000000100d800da, s2=0x0000c0fefd15cb79) + 35 at strutil.cpp:66
    frame #1: 0x00000001001c6bf5 d2x-rebirth`find_hli_entry() + 133 at playsave.cpp:1095
    frame #2: 0x00000001001c6aea d2x-rebirth`set_highest_level(levelnum=1) + 58 at playsave.cpp:1121
    frame #3: 0x00000001000eb3de d2x-rebirth`StartNewLevelSub(level_num=1, page_in_textures=1, secret_flag=0) + 878 at gameseq.cpp:1729
    frame #4: 0x00000001000e867d d2x-rebirth`StartNewLevel(level_num=1) + 93 at gameseq.cpp:1888
    frame #5: 0x00000001000e8256 d2x-rebirth`StartNewGame(start_level=1) + 118 at gameseq.cpp:764
    frame #6: 0x000000010015432e d2x-rebirth`do_new_game_menu() + 734 at menu.cpp:856
    frame #7: 0x000000010015ca5f d2x-rebirth`mission_menu_handler(lb=0x00006000000e5600, event=0x00007fff5fbfe3a0, mm=0x0000600000026e60) + 335 at mission.cpp:972
    frame #8: 0x000000010019fed4 d2x-rebirth`listbox_key_command(wind=0x00006000000e5180, event=0x00007fff5fbfe4f8, lb=0x00006000000e5600) + 516 at newmenu.cpp:1823
    frame #9: 0x000000010019f6e5 d2x-rebirth`listbox_handler(wind=0x00006000000e5180, event=0x00007fff5fbfe4f8, lb=0x00006000000e5600) + 325 at newmenu.cpp:2026
    frame #10: 0x0000000100013d05 d2x-rebirth`window_send_event(wind=0x00006000000e5180, event=0x00007fff5fbfe4f8) + 53 at window.cpp:208
    frame #11: 0x000000010005293d d2x-rebirth`event_send(event=0x00007fff5fbfe4f8) + 109 at event.cpp:132
    frame #12: 0x0000000100053985 d2x-rebirth`key_handler(kevent=0x00007fff5fbfe810) + 2245 at key.cpp:434
    frame #13: 0x0000000100052749 d2x-rebirth`event_poll() + 329 at event.cpp:45
    frame #14: 0x0000000100052a5b d2x-rebirth`event_process() + 27 at event.cpp:154
    frame #15: 0x000000010012c511 d2x-rebirth`SDL_main(argc=3, argv=0x0000618000023240) + 1729 at inferno.cpp:547
(lldb) fr v
(const unsigned char *) s1 = 0x0000000100d800da ""
(const unsigned char *) s2 = 0x0000c0fefd15cb79 ""
(int) u1 = 0
(int) u2 = 0
(lldb) up
frame #1: 0x00000001001c6bf5 d2x-rebirth`find_hli_entry() + 133 at playsave.cpp:1095
   1092     int i;
   1093 
   1094     for (i=0;i < PlayerCfg.NHighestLevels;i++)
-> 1095         if (!d_stricmp(PlayerCfg.HighestLevels[i].Shortname, Current_mission_filename))
   1096             break;
   1097 
   1098     if (i==PlayerCfg.NHighestLevels) { //not found. create entry
(lldb) fr v
(int) i = 0
(lldb) up
frame #2: 0x00000001001c6aea d2x-rebirth`set_highest_level(levelnum=1) + 58 at playsave.cpp:1121
   1118         if (ret != ENOENT)      //if file doesn't exist, that's ok
   1119             return;
   1120 
-> 1121     i = find_hli_entry();
   1122 
   1123     if (levelnum > PlayerCfg.HighestLevels[i].LevelNum)
   1124     {
(lldb) fr v
(int) levelnum = 1
(int) ret = 0
(int) i = 0
(lldb) up
frame #3: 0x00000001000eb3de d2x-rebirth`StartNewLevelSub(level_num=1, page_in_textures=1, secret_flag=0) + 878 at gameseq.cpp:1729
   1726 #endif
   1727 
   1728     if (!(Game_mode & GM_MULTI) && !cheats.enabled)
-> 1729         set_highest_level(Current_level_num);
   1730     else
   1731         read_player_file();     //get window sizes
   1732 
(lldb) fr v
(int) level_num = 1
(int) page_in_textures = 1
(int) secret_flag = 0
(lldb) up
frame #4: 0x00000001000e867d d2x-rebirth`StartNewLevel(level_num=1) + 93 at gameseq.cpp:1888
   1885     ShowLevelIntro(level_num);
   1886 #endif
   1887 
-> 1888     StartNewLevelSub(level_num, 1, 0 );
   1889 
   1890 }
   1891 
(lldb) fr v
(int) level_num = 1
(lldb) up
frame #5: 0x00000001000e8256 d2x-rebirth`StartNewGame(start_level=1) + 118 at gameseq.cpp:764
   761          StartNewLevelSecret(start_level, 0);
   762      else
   763  #endif
-> 764          StartNewLevel(start_level);
   765  
   766      Players[Player_num].starting_level = start_level;       // Mark where they started
   767  
(lldb) fr v
(int) start_level = 1
(lldb) up
frame #6: 0x000000010015432e d2x-rebirth`do_new_game_menu() + 734 at menu.cpp:856
   853      if (!do_difficulty_menu())
   854          return 0;
   855  
-> 856      StartNewGame(new_level_num);
   857  
   858      return 1;   // exit mission listbox
   859  }
(lldb) fr v
(int) new_level_num = 1
(int) player_highest_level = 24
(lldb) up
frame #7: 0x000000010015ca5f d2x-rebirth`mission_menu_handler(lb=0x00006000000e5600, event=0x00007fff5fbfe3a0, mm=0x0000600000026e60) + 335 at mission.cpp:972
   969                      return 1;   // stay in listbox so user can select another one
   970                  }
   971              }
-> 972              return !(*mm->when_selected)();
   973              break;
   974  
   975          case EVENT_WINDOW_CLOSE:
(lldb) fr v
(listbox *) lb = 0x00006000000e5600
(const d_event &) event = 0x00007fff5fbfe3a0: {
  type = EVENT_NEWMENU_SELECTED
}
(mission_menu *) mm = 0x0000600000026e60
(const unsigned char **) list = 0x0000600000026f80
(int) citem = 0

@btb
Copy link
Contributor Author

btb commented Dec 8, 2014

If I run it outside the debugger, I can play the builtin mission, but vertigo crashes, and the OS reports:

Thread 0 Crashed:: Dispatch queue: com.apple.main-thread
0   d2x-rebirth                     0x0000000100ecbaf5 d_debugbreak() + 5
1   d2x-rebirth                     0x0000000100ecbd35 Error(char const*, unsigned int, char const*, ...) + 485
2   d2x-rebirth                     0x0000000100f3016b bm_read_extra_robots(char const*, int) + 75
3   d2x-rebirth                     0x000000010100ca4f load_mission_ham() + 1039
4   d2x-rebirth                     0x0000000101011040 load_mission(mle const*) + 15728
5   d2x-rebirth                     0x00000001010119d5 mission_menu_handler(listbox*, d_event const&, mission_menu*) + 197
6   d2x-rebirth                     0x0000000101054ed4 listbox_key_command(window*, d_event const&, listbox*) + 516
7   d2x-rebirth                     0x00000001010546e5 listbox_handler(window*, d_event const&, listbox*) + 325
8   d2x-rebirth                     0x0000000100ec8d05 window_send_event(window*, d_event const&) + 53
9   d2x-rebirth                     0x0000000100f0793d event_send(d_event const&) + 109
10  d2x-rebirth                     0x0000000100f08985 key_handler(SDL_KeyboardEvent*) + 2245
11  d2x-rebirth                     0x0000000100f07749 event_poll() + 329
12  d2x-rebirth                     0x0000000100f07a5b event_process() + 27
13  d2x-rebirth                     0x0000000100fe1511 SDL_main + 1729

@btb
Copy link
Contributor Author

btb commented Dec 8, 2014

Also maybe of note, after applying f1a6278, the vertigo mission plays, but still never displays the briefing screens or the robot movies.

vLKp added a commit that referenced this issue Dec 8, 2014
Mission names are passed in without an extension.  Short mission names
read beyond the end of the buffer, causing AddressSanitizer to kill the
program.

Reported by btb: #20
@vLKp
Copy link
Contributor

vLKp commented Dec 8, 2014

Playing Vertigo crashed for me when using AddressSanitizer. Playing custom missions was fine both with and without AddressSanitizer. Your crash starting a builtin mission is different. I cannot reproduce it, but it might be dependent on some data from the player profile.

I see an abort starting Vertigo level 1 at similar/main/gamesave.cpp:1109 from a sanity check on whether a materialization center trigger is set correctly. Running NDEBUG bypasses that Int3 and the game plays normally. I wonder if the level is actually broken or if the Int3 is legitimate.

Commit 7c24f68 allows Vertigo briefings to play for me. Commit 84011e5 switches find_hli_entry to use partial_range, which should throw an exception if you have an invalid NHighestLevels. Do you see different results when running with 84011e5?

I do not see the Vertigo abort in bm_read_extra_robots. Can you determine which line calls Error?

@btb
Copy link
Contributor Author

btb commented Dec 8, 2014

results are the same with 84011e5. I do get the Vertigo briefings now, provided I still have this revert applied.

@btb
Copy link
Contributor Author

btb commented Dec 8, 2014

It's dying at Error("Failed to open HAM file \"%s\"", fname);
But I don't get the error messagebox, or anything printed on the console except "Trace/BPT trap: 5"
If I put a printf in there I see that fname = ".ham"

@vLKp
Copy link
Contributor

vLKp commented Dec 9, 2014

You get no output because both Error_puts and Error call Int3 before printing their message. Zico moved the Int3 from after print_exit_message to before it in d9e2337. That move was meaningless until your recent pull request for reactivating Int3. Now, it actually interrupts and kills the program. :) Commit a270317 moves the Int3 back below the printing.

For your larger problem, somehow you are ending up with Current_mission_filename = "" while Current_mission->enhanced != 0. When I start Vertigo with a270317, I have Current_mission->enhanced = 2 and Current_mission_filename = "d2x". Neither Valgrind nor AddressSanitizer report any problems starting Vertigo mission 1 for me with that commit.

At the time of the error, what is the output of p Current_mission? Where do you keep your Vertigo files?

@btb
Copy link
Contributor Author

btb commented Dec 9, 2014

(lldb) p Current_mission
(Mission_ptr) $0 = {
  __ptr_ = {
    std::__1::__libcpp_compressed_pair_imp<Mission *, std::__1::default_delete<Mission>, 2> = {
      __first_ = 0x0000618000102eb0
    }
  }
}
$ pwd
/Users/bradleyb/Library/Preferences/D2X Rebirth
$ find .
.
./btb.plr
./btb.plx
./d2x.ini
./data
./data/alien1.pig
./data/alien2.pig
./data/d2x-h.mvl
./data/d2x-l.mvl
./data/demos
./data/demos/descent2.dem
./data/descent.cfg
./data/descent2.ham
./data/descent2.hog
./data/descent2.ico
./data/descent2.s11
./data/descent2.s22
./data/descentg.ini
./data/fire.pig
./data/groupa.pig
./data/hoard.ham
./data/ice.pig
./data/intro-h.mvl
./data/missions
./data/missions/d2-2plyr.hog
./data/missions/d2-2plyr.mn2
./data/missions/d2chaos.hog
./data/missions/d2chaos.mn2
./data/missions/d2x.hog
./data/missions/d2x.mn2
./data/missions/panic.hog
./data/missions/panic.mn2
./data/other-h.mvl
./data/readme.txt
./data/robots-h.mvl
./data/robots-l.mvl
./data/water.pig
./descent.cfg
./gamelog.txt

@vLKp
Copy link
Contributor

vLKp commented Dec 14, 2014

That debugger output was less helpful than I expected. I want to see the contents of the Mission pointed at by Current_mission; the command only printed the memory address of the Mission.

@btb
Copy link
Contributor Author

btb commented Dec 25, 2014

I agree. It seems inordinately difficult to work with these complex data types in lldb, perhaps its easier in gdb, I haven't tried lately.
I'll try to get a better llook inside soon.

@btb
Copy link
Contributor Author

btb commented Jan 3, 2015

the problem seems to be that Current_mission is not properly initialized. In in load_mission(), immediately after executing:
Current_mission = make_unique<Mission>();
I get:

p Current_mission
(Mission_ptr) $1 = {
  __ptr_ = {
    std::__1::__libcpp_compressed_pair_imp<Mission *, std::__1::default_delete<Mission>, 2> = {
      __first_ = 0x00006100000e3e80
    }
  }
}
p *Current_mission
error: call to a function 'std::__1::unique_ptr<Mission, std::__1::default_delete<Mission> >::operator*() const' ('_ZNKSt3__110unique_ptrI7MissionNS_14default_deleteIS1_EEEdeEv') that is not present in the target
error: 0 errors parsing expression
error: The expression could not be prepared to run in the target

If I execute the next line:
Current_mission->builtin_hogsize = mission->builtin_hogsize;
It doesn't crash, but I just get:

p Current_mission->builtin_hogsize
error: call to a function 'std::__1::unique_ptr<Mission, std::__1::default_delete<Mission> >::operator->() const' ('_ZNKSt3__110unique_ptrI7MissionNS_14default_deleteIS1_EEEptEv') that is not present in the target
error: 0 errors parsing expression
error: The expression could not be prepared to run in the target

Note that DXX_HAVE_CXX14_MAKE_UNIQUE is false for me, so it's using the workarounds in compiler-make_unique.h

@vLKp
Copy link
Contributor

vLKp commented Jan 4, 2015

I read that to be that your compiler did not emit an out-of-line copy of operator_() or operator->(), and the debugger cannot figure out how to evaluate the expression without that out-of-line copy. What happens if you try _p _Current_mission._ptr.first? That expression should take the variable Current_mission, explicitly name each of the submembers down to the actual pointer, then dereference that, which should work even without the out-of-line operators.

@vLKp
Copy link
Contributor

vLKp commented Jan 4, 2015

Sorry for the Github markdown problems. Preview/Edit does not work for me, and the Markdown parser seems to be written with the idea that no one will write code in the middle of a sentence.

@Matt1360
Copy link
Contributor

Matt1360 commented Jan 4, 2015

Use the backtick to surround inline code. i am code, unless I'm very
wrong, or it doesn't work when writing from an email :)
On Jan 3, 2015 8:32 PM, "vLKp" notifications@github.com wrote:

Sorry for the Github markdown problems. Preview/Edit does not work for me,
and the Markdown parser seems to be written with the idea that no one will
write code in the middle of a sentence.


Reply to this email directly or view it on GitHub
#20 (comment)
.

@Matt1360
Copy link
Contributor

Matt1360 commented Jan 4, 2015

Now I'm interested if I'm wrong while on the mobile site. Maybe I'm too used to gitlab.

@btb
Copy link
Contributor Author

btb commented Jan 4, 2015

That seems right. Did I mention I don't really get modern c++?

-Brad

On Jan 3, 2015, at 5:31 PM, vLKp notifications@github.com wrote:

I read that to be that your compiler did not emit an out-of-line copy of
operator_() or operator->(), and the debugger cannot figure out how to
evaluate the expression without that out-of-line copy. What happens if you
try _p _Current_mission._ptr.first? That expression should take the
variable Current_mission, explicitly name each of the submembers down to
the actual pointer, then dereference that, which should work even without
the out-of-line operators.


Reply to this email directly or view it on GitHub
#20 (comment)
.

@vLKp
Copy link
Contributor

vLKp commented Jan 4, 2015

Well, a working preview would help too, so I could check for and fix these things. Instead Preview just jumps to the top of the page. Yay buggy AJAX.

@btb
Copy link
Contributor Author

btb commented Jan 11, 2015

in load_mission(), after Current_mission->filename = next(begin(Current_mission->path), distance(begin(mission->path), mission->filename));

(lldb) p *Current_mission.__ptr_.__first_
(Mission) $4 = {
  filename = (item = <read memory from 0xc0fefeae1499 failed (0 of 1 bytes read)>)
  path = "d2x"
  secret_level_table = {
    __ptr_ = {
      std::__1::__libcpp_compressed_pair_imp<unsigned char *, std::__1::default_delete<unsigned char []>, 2> = (__first_ = unsigned char * = 0x0000000000000000)
    }
  }
  level_names = {
    __ptr_ = {
      std::__1::__libcpp_compressed_pair_imp<d_fname *, std::__1::default_delete<d_fname []>, 2> = {
        __first_ = 0x0000000000000000
      }
    }
  }
  secret_level_names = {
    __ptr_ = {
      std::__1::__libcpp_compressed_pair_imp<d_fname *, std::__1::default_delete<d_fname []>, 2> = {
        __first_ = 0x0000000000000000
      }
    }
  }
  builtin_hogsize = 0
  mission_name = {
    std::__1::array<unsigned char, 26> = {
      __elems_ = {
        [0] = 'D'
        [1] = 'e'
        [2] = 's'
        [3] = 'c'
        [4] = 'e'
        [5] = 'n'
        [6] = 't'
        [7] = ' '
        [8] = '2'
        [9] = ':'
        [10] = ' '
        [11] = 'V'
        [12] = 'e'
        [13] = 'r'
        [14] = 't'
        [15] = 'i'
        [16] = 'g'
        [17] = 'o'
        [18] = '\0'
        [19] = '\0'
        [20] = '\0'
        [21] = '\0'
        [22] = '\0'
        [23] = '\0'
        [24] = '\0'
        [25] = '\0'
      }
    }
  }
  briefing_text_filename = {
    ntstring<12> = {
      std::__1::array<unsigned char, 13> = {
        __elems_ = ([0] = '\0', [1] = '\0', [2] = '\0', [3] = '\0', [4] = '\0', [5] = '\0', [6] = '\0', [7] = '\0', [8] = '\0', [9] = '\0', [10] = '\0', [11] = '\0', [12] = '\0')
      }
    }
  }
  ending_text_filename = {
    ntstring<12> = {
      std::__1::array<unsigned char, 13> = {
        __elems_ = ([0] = '\0', [1] = '\0', [2] = '\0', [3] = '\0', [4] = '\0', [5] = '\0', [6] = '\0', [7] = '\0', [8] = '\0', [9] = '\0', [10] = '\0', [11] = '\0', [12] = '\0')
      }
    }
  }
  anarchy_only_flag = '\0'
  last_level = '\0'
  last_secret_level = '\0'
  n_secret_levels = '\0'
  descent_version = '\x02'
  enhanced = '\0'
  alternate_ham_file = {
    __ptr_ = {
      std::__1::__libcpp_compressed_pair_imp<d_fname *, std::__1::default_delete<d_fname>, 2> = {
        __first_ = 0x0000000000000000
      }
    }
  }
}
(lldb) p mission->path
(std::__1::string) $2 = "d2x"
(lldb) p mission->filename
(std::__1::basic_string<unsigned char, std::__1::char_traits<unsigned char>, std::__1::allocator<unsigned char> >::const_iterator) $3 = (item = '\0')

so mission->filename is empty here, but it appears that it was okay in read_mission_file. It looks like this:

(lldb) p mission->filename
(std::__1::basic_string<unsigned char, std::__1::char_traits<unsigned char>, std::__1::allocator<unsigned char> >::const_iterator) $2 = (item = 'd')

@vLKp
Copy link
Contributor

vLKp commented Jan 12, 2015

Can you disable the lldb pretty-printer? It is hiding useful information, such as where the iterator really points. We indirectly see that information after the iterator breaks because of the error message about being unable to read the string, but in the good case, we only see the value referenced by the iterator, but not its address.

The line you identified is the C++ equivalent of newptr = newbase + (oldptr - oldbase);. Your output shows that after the assignment, newptr points to unreadable memory, when it should be pointing to the filename portion of the path. Can you print the raw values of begin(Current_mission->path), begin(mission->path), mission->filename, and the result of distance(begin(mission->path), mission->filename)? That will show newbase, oldbase, oldptr, and (oldptr - oldbase). I expect one of those will be a bogus value, leading to a bogus output.

@btb
Copy link
Contributor Author

btb commented Jan 12, 2015

haven't figured out how to get begin or distance to work, but i got this:

(lldb) frame variable -R mission->path
(std::__1::string) mission->path = {
  __r_ = {
    std::__1::__libcpp_compressed_pair_imp<std::__1::basic_string<unsigned char, std::__1::char_traits<unsigned char>, std::__1::allocator<unsigned char> >::__rep, std::__1::allocator<unsigned char>, 2> = {
      __first_ = {
         = {
          __l = {
            __cap_ = 2016568326
            __size_ = 0
            __data_ = 0x0000000000000000
          }
          __s = {
             = {
              __size_ = '\x06'
              __lx = '\x06'
            }
            __data_ = {
              [0] = 'd'
              [1] = '2'
              [2] = 'x'
              [3] = '\0'
              [4] = '\0'
              [5] = '\0'
              [6] = '\0'
              [7] = '\0'
              [8] = '\0'
              [9] = '\0'
              [10] = '\0'
              [11] = '\0'
              [12] = '\0'
              [13] = '\0'
              [14] = '\0'
              [15] = '\0'
              [16] = '\0'
              [17] = '\0'
              [18] = '\0'
              [19] = '\0'
              [20] = '\0'
              [21] = '\0'
              [22] = '\0'
            }
          }
          __r = {
            __words = {
              [0] = 2016568326
              [1] = 0
              [2] = 0
            }
          }
        }
      }
    }
  }
}
(lldb) frame variable -R mission->filename
(std::__1::basic_string<unsigned char, std::__1::char_traits<unsigned char>, std::__1::allocator<unsigned char> >::const_iterator) mission->filename = {
  __i = 0x0000600000103a61
}
(lldb) fr variable -R Current_mission.__ptr_.__first_->path
(std::__1::string) Current_mission.__ptr_.__first_->path = {
  __r_ = {
    std::__1::__libcpp_compressed_pair_imp<std::__1::basic_string<unsigned char, std::__1::char_traits<unsigned char>, std::__1::allocator<unsigned char> >::__rep, std::__1::allocator<unsigned char>, 2> = {
      __first_ = {
         = {
          __l = {
            __cap_ = 2016568326
            __size_ = 0
            __data_ = 0x0000000000000000
          }
          __s = {
             = {
              __size_ = '\x06'
              __lx = '\x06'
            }
            __data_ = {
              [0] = 'd'
              [1] = '2'
              [2] = 'x'
              [3] = '\0'
              [4] = '\0'
              [5] = '\0'
              [6] = '\0'
              [7] = '\0'
              [8] = '\0'
              [9] = '\0'
              [10] = '\0'
              [11] = '\0'
              [12] = '\0'
              [13] = '\0'
              [14] = '\0'
              [15] = '\0'
              [16] = '\0'
              [17] = '\0'
              [18] = '\0'
              [19] = '\0'
              [20] = '\0'
              [21] = '\0'
              [22] = '\0'
            }
          }
          __r = {
            __words = {
              [0] = 2016568326
              [1] = 0
              [2] = 0
            }
          }
        }
      }
    }
  }
}
(lldb) fr variable -R Current_mission.__ptr_.__first_->filename
(std::__1::basic_string<unsigned char, std::__1::char_traits<unsigned char>, std::__1::allocator<unsigned char> >::const_iterator) Current_mission.__ptr_.__first_->filename = {
  __i = 0x0000c17efebdedc9
}

@btb
Copy link
Contributor Author

btb commented Jan 12, 2015

okay then

(lldb) p &mission->path.__r_.__first_.__s.__data_[0]
(const value_type *) $13 = 0x0000000101607021 "d2x"
(lldb) p &Current_mission.__ptr_.__first_->path.__r_.__first_.__s.__data_[0]
(value_type *) $8 = 0x00006180000e2389 "d2x"

@vLKp
Copy link
Contributor

vLKp commented Jan 12, 2015

Your debugger is probably refusing to evaluate those because they are fully inline. Try adding this block after the assignment of Current_mission->filename, which should print the desired fields. I split them into individual calls in case any of them fault.

    printf("mission->path = %p\n", &mission->path[0]);
    printf("mission->filename = %p\n", &*mission->filename);
    printf("Current_mission->path = %p\n", &Current_mission->path[0]);
    printf("distance(Current_mission->path) = %zu\n", distance(begin(mission->path), mission->filename));
    printf("begin(Current_mission->path) = %p\n", &*begin(Current_mission->path));
    printf("Current_mission->filename = %p\n", &*Current_mission->filename);

@vLKp
Copy link
Contributor

vLKp commented Jan 12, 2015

Is all that output from a single run? If so, something is very wrong. Your mission->path is 0x0000000101607021, but mission->filename is 0x0000600000103a61. They should be very close in value.

@btb
Copy link
Contributor Author

btb commented Jan 12, 2015

yeah, same run. mission->filename is getting clobbered somewhere between read_mission_file() and load_mission()

I'm having a hard time figuring out where, because lldb bizarrely won't even acknowledge the existence of the mission_list variable when in the frame of build_mission_list() - I even tried renaming the mission_list typedef in case there was a bug with name collision, but that didn't help.

@btb
Copy link
Contributor Author

btb commented Jan 12, 2015

Actually no. what happens is that path moves somewhere else in memory, but filename stays pointing at the old location.

It appears that mission_list.emplace_back() reallocates the entire list, then copies the old values over, not preserving the relationship between path and filename

I only have 2 missions installed now, the builtin mission d2, and d2x.mn2.

We're in read_mission_file(), the d2 mission has already been loaded:

(lldb) fr va mission_list
(mission_list &) mission_list = size=1: {
  [0] = {
    filename = (item = 'd')
    builtin_hogsize = 7595079
    mission_name = {
      std::__1::array<unsigned char, 26> = {
        __elems_ = {
          [0] = 'D'
          [1] = 'e'
          [2] = 's'
          [3] = 'c'
          [4] = 'e'
          [5] = 'n'
          [6] = 't'
          [7] = ' '
          [8] = '2'
          [9] = ':'
          [10] = ' '
          [11] = 'C'
          [12] = 'o'
          [13] = 'u'
          [14] = 'n'
          [15] = 't'
          [16] = 'e'
          [17] = 'r'
          [18] = 's'
          [19] = 't'
          [20] = 'r'
          [21] = 'i'
          [22] = 'k'
          [23] = 'e'
          [24] = '!'
          [25] = '\0'
        }
      }
    }
    descent_version = '\x02'
    anarchy_only_flag = '\0'
    path = "d2"
    location = ML_CURDIR
  }
}
(lldb) fr va -R &mission_list[0].path.__r_.__first_.__s.__data_
(value_type (*)[23]) &__data_ = 0x0000600000085f29
(lldb) fr va -R mission_list[0].filename
(std::__1::basic_string<unsigned char, std::__1::char_traits<unsigned char>, std::__1::allocator<unsigned char> >::const_iterator) mission_list[0].filename = {
  __i = 0x0000600000085f29
}

then mission_list.emplace_back(); is called, and:

(lldb) fr va mission_list
(mission_list &) mission_list = size=2: {
  [0] = {
    filename = (item = '\r')
    builtin_hogsize = 7595079
    mission_name = {
      std::__1::array<unsigned char, 26> = {
        __elems_ = {
          [0] = 'D'
          [1] = 'e'
          [2] = 's'
          [3] = 'c'
          [4] = 'e'
          [5] = 'n'
          [6] = 't'
          [7] = ' '
          [8] = '2'
          [9] = ':'
          [10] = ' '
          [11] = 'C'
          [12] = 'o'
          [13] = 'u'
          [14] = 'n'
          [15] = 't'
          [16] = 'e'
          [17] = 'r'
          [18] = 's'
          [19] = 't'
          [20] = 'r'
          [21] = 'i'
          [22] = 'k'
          [23] = 'e'
          [24] = '!'
          [25] = '\0'
        }
      }
    }
    descent_version = '\x02'
    anarchy_only_flag = '\0'
    path = "d2"
    location = ML_CURDIR
  }
  [1] = {
    filename = ()
    builtin_hogsize = 0
    mission_name = {
      std::__1::array<unsigned char, 26> = {
        __elems_ = {
          [0] = '\0'
          [1] = '\0'
          [2] = '\0'
          [3] = '\0'
          [4] = '\0'
          [5] = '\0'
          [6] = '\0'
          [7] = '\0'
          [8] = '\0'
          [9] = '\0'
          [10] = '\0'
          [11] = '\0'
          [12] = '\0'
          [13] = '\0'
          [14] = '\0'
          [15] = '\0'
          [16] = '\0'
          [17] = '\0'
          [18] = '\0'
          [19] = '\0'
          [20] = '\0'
          [21] = '\0'
          [22] = '\0'
          [23] = '\0'
          [24] = '\0'
          [25] = '\0'
        }
      }
    }
    descent_version = '\0'
    anarchy_only_flag = '\0'
    path = ""
    location = ML_CURDIR
  }
}
(lldb) fr va -R &mission_list[0].path.__r_.__first_.__s.__data_
(value_type (*)[23]) &__data_ = 0x0000600000105099
(lldb) fr va -R mission_list[0].filename
(std::__1::basic_string<unsigned char, std::__1::char_traits<unsigned char>, std::__1::allocator<unsigned char> >::const_iterator) mission_list[0].filename = {
  __i = 0x0000600000085f29
}

@btb
Copy link
Contributor Author

btb commented Jan 12, 2015

obviously it worked before fea751b because path was malloc'd and therefore didn't change.

@vLKp
Copy link
Contributor

vLKp commented Jan 13, 2015

Valgrind shows no sign of problems here, but your explanation is mostly reasonable. Moving path elsewhere in memory should be fine, unless the small string optimization is in effect or your std::string is copied instead of moved. Your earlier output seems to show a 22-byte buffer for the small string optimization, which could cause it to apply fairly often. This should be fixable by defining a move constructor to update ->filename when mle is moved elsewhere.

@vLKp
Copy link
Contributor

vLKp commented Jan 13, 2015

Please sync to 24bdbfb and try again.

@vLKp
Copy link
Contributor

vLKp commented Jan 14, 2015

b175c94 provides a simpler fix, and occurs after ea3c789 (which fixes issue #31).

@btb
Copy link
Contributor Author

btb commented Jan 15, 2015

looks like that will do it.

@btb btb closed this as completed Jan 15, 2015
@vLKp vLKp added this to the 0.60 milestone Sep 22, 2015
vLKp added a commit that referenced this issue Dec 8, 2018
Commit 88b5e61 ("Replace calls to
window_set_visible in DoPlayerDead() with stop/start_time()") switched
from hiding the game window to only stopping time, and that only if
hiding the window would have stopped time.  In multiplayer, this allows
time to continue running.  This introduced a crash if the player dies
during the mine countdown.  When the player dies, the game checks if the
reactor has been destroyed.  If so, the game immediately advances to the
next level.  That advance will try to draw the game window if it is
visible.  When the window is drawn, if time is not stopped, then game
logic runs.  Some of that logic is not prepared to deal with the
inconsistent state present when a new level is only partially loaded.
That inconsistent state then causes a crash.  Call stack:

    #11 slew_frame () at similar/main/slew.cpp:152
    #12 in d2x::object_move_one () at similar/main/object.cpp:1758
    #13 in d2x::object_move_all () at similar/main/object.cpp:1956
    #14 in d2x::GameProcessFrame () at similar/main/game.cpp:1848
    #15 d2x::game_handler () at similar/main/game.cpp:1615
    #16 in dcx::window_send_event () at common/include/window.h:116
    #17 dcx::event_process () at common/arch/sdl/event.cpp:176
    #18 in newmenu_do2 () at similar/main/newmenu.cpp:498
    #19 in newmenu_do2<dcx::unused_newmenu_userdata_t> () at common/main/newmenu.h:184
    #20 newmenu_do<dcx::unused_newmenu_userdata_t const> () at common/main/newmenu.h:190
    #21 newmenu_do<1ul, dcx::unused_newmenu_userdata_t const> () at common/main/newmenu.h:196
    #22 net_udp_wait_for_requests () at similar/main/net_udp.cpp:4563
    #23 net_udp_level_sync () at similar/main/net_udp.cpp:4607
    #24 in multi_level_sync () at similar/main/multi.cpp:3458
    #25 in d2x::StartNewLevelSub () at similar/main/gameseq.cpp:1803
    #26 in d2x::StartNewLevel () at similar/main/gameseq.cpp:2018
    #27 in d2x::AdvanceLevel () at similar/main/gameseq.cpp:1648
    #28 in d2x::DoPlayerDead () at similar/main/gameseq.cpp:1721

The root cause of this is the layering violation:
- Killing the player can have the side effect of advancing the level
- Advancing the level can have the side effect of calling multiplayer code while the level data is in an inconsistent state
- Calling multiplayer code can cause the event system to redraw the game
- Redrawing the game can cause game logic to run

Hack around this by restoring the logic that hides the game window, so
that the window is not redrawn and the game logic is not run.  This does
not fix the layering problem, but prevents crashing affected users.  To
avoid undoing the feature from the breaking commit, hide the window only
when advancing to a new level, rather than unconditionally.  A player
advancing to a new level already lacks the move-at-cold-start capability
even on successfully escaping the mine, so no functionality is lost with
this change.  Players who are dead and do not advance to a new level
retain that capability.

Fixes: 88b5e61 ("Replace calls to window_set_visible in DoPlayerDead() with stop/start_time()")
Reported-by: Ninjared <https://forum.dxx-rebirth.com/showthread.php?tid=1097>
vLKp added a commit that referenced this issue Dec 8, 2018
commit d83972d upstream.

Commit 88b5e61 ("Replace calls to
window_set_visible in DoPlayerDead() with stop/start_time()") switched
from hiding the game window to only stopping time, and that only if
hiding the window would have stopped time.  In multiplayer, this allows
time to continue running.  This introduced a crash if the player dies
during the mine countdown.  When the player dies, the game checks if the
reactor has been destroyed.  If so, the game immediately advances to the
next level.  That advance will try to draw the game window if it is
visible.  When the window is drawn, if time is not stopped, then game
logic runs.  Some of that logic is not prepared to deal with the
inconsistent state present when a new level is only partially loaded.
That inconsistent state then causes a crash.  Call stack:

    #11 slew_frame () at similar/main/slew.cpp:152
    #12 in d2x::object_move_one () at similar/main/object.cpp:1758
    #13 in d2x::object_move_all () at similar/main/object.cpp:1956
    #14 in d2x::GameProcessFrame () at similar/main/game.cpp:1848
    #15 d2x::game_handler () at similar/main/game.cpp:1615
    #16 in dcx::window_send_event () at common/include/window.h:116
    #17 dcx::event_process () at common/arch/sdl/event.cpp:176
    #18 in newmenu_do2 () at similar/main/newmenu.cpp:498
    #19 in newmenu_do2<dcx::unused_newmenu_userdata_t> () at common/main/newmenu.h:184
    #20 newmenu_do<dcx::unused_newmenu_userdata_t const> () at common/main/newmenu.h:190
    #21 newmenu_do<1ul, dcx::unused_newmenu_userdata_t const> () at common/main/newmenu.h:196
    #22 net_udp_wait_for_requests () at similar/main/net_udp.cpp:4563
    #23 net_udp_level_sync () at similar/main/net_udp.cpp:4607
    #24 in multi_level_sync () at similar/main/multi.cpp:3458
    #25 in d2x::StartNewLevelSub () at similar/main/gameseq.cpp:1803
    #26 in d2x::StartNewLevel () at similar/main/gameseq.cpp:2018
    #27 in d2x::AdvanceLevel () at similar/main/gameseq.cpp:1648
    #28 in d2x::DoPlayerDead () at similar/main/gameseq.cpp:1721

The root cause of this is the layering violation:
- Killing the player can have the side effect of advancing the level
- Advancing the level can have the side effect of calling multiplayer code while the level data is in an inconsistent state
- Calling multiplayer code can cause the event system to redraw the game
- Redrawing the game can cause game logic to run

Hack around this by restoring the logic that hides the game window, so
that the window is not redrawn and the game logic is not run.  This does
not fix the layering problem, but prevents crashing affected users.  To
avoid undoing the feature from the breaking commit, hide the window only
when advancing to a new level, rather than unconditionally.  A player
advancing to a new level already lacks the move-at-cold-start capability
even on successfully escaping the mine, so no functionality is lost with
this change.  Players who are dead and do not advance to a new level
retain that capability.

Fixes: 88b5e61 ("Replace calls to window_set_visible in DoPlayerDead() with stop/start_time()")
Reported-by: Ninjared <https://forum.dxx-rebirth.com/showthread.php?tid=1097>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants