Firmware 151 takes 9seconds to boot verses 150 3seconds

Hi,
I’ve recently updated to the latest release of the firmware (v1.5.1) and have noticed that my setup is taking nearly 9 seconds to boot. Below is a sample output of the following code that I’ve run on both firmware versions.
I can fix this and speed things up by single_threading my routine, but would like to try and avoid that. Any ideas as to why this is happening?

Code used

SYSTEM_THREAD(ENABLED);
SYSTEM_MODE(MANUAL);

Logger lu("lu");
StreamLogHandler* loggingHandler;

void scan_i2c_bus() {
  lu("Scanning I2C bus");
  String found;
  String errors;

  SINGLE_THREADED_BLOCK(){ //Remove to slow startup down.
    for(int address = 1; address < 127; address++ )
    {
      Wire.beginTransmission(address);
      uint8_t error = Wire.endTransmission();
      lu("Processing :%d",address);
      if (error == 0)
      {
        found += String::format("[%02x]", address);
      }
      else if (error==4)
      {
        
        errors += String::format("[%02x]", address);
      }    
    }
  }
  
  lu("I2C devices at addr %s", found.c_str());
  if (errors.length() > 0) {
    lu("I2C errors at addr %s", errors.c_str());
  }
  lu("Finished scanning I2C bus");
}

void setup() {
  WiFi.off();
  loggingHandler=new Serial1LogHandler(57600,LOG_LEVEL_ALL,{{ "lu",LOG_LEVEL_ALL}});
  Wire.begin();
  scan_i2c_bus();
  lu("Done Setup");
}


void loop() {
  delay(5000);
}

Output from code without single_threaded_block

0000000272 [lu] INFO: Scanning I2C bus
0000000324 [lu] INFO: Processing :1
0000000376 [lu] INFO: Processing :2
0000000428 [lu] INFO: Processing :3
0000000480 [lu] INFO: Processing :4
0000000532 [lu] INFO: Processing :5
0000001563 [ncp.at] TRACE: > AT
0000001564 [ncp.at] TRACE: < OK
0000002564 [hal] TRACE: NCP ready to accept AT commands
0000002564 [ncp.at] TRACE: > AT+CMUX=0
0000002566 [ncp.at] TRACE: < OK
0000002568 [gsm0710muxer] INFO: Starting GSM07.10 muxer
0000002580 [gsm0710muxer] INFO: Openning mux channel 0
0000002580 [gsm0710muxer] INFO: GSM07.10 muxer thread started
0000002603 [lu] INFO: Processing :6
0000002652 [gsm0710muxer] INFO: Resuming channel 0
0000002652 [gsm0710muxer] INFO: Openning mux channel 1
0000002654 [lu] INFO: Processing :7
0000002722 [lu] INFO: Processing :8
0000002753 [gsm0710muxer] INFO: Resuming channel 1
0000002753 [gsm0710muxer] INFO: Resuming channel 1
0000002754 [ncp.at] TRACE: > AT
0000002774 [lu] INFO: Processing :9
0000002806 [ncp.at] TRACE: < OK
0000002806 [ncp.at] TRACE: > AT+CWDHCP=0,3
0000002826 [lu] INFO: Processing :10
0000002856 [ncp.at] TRACE: < OK
0000002856 [hal] TRACE: NCP state changed: 1
0000002856 [net.esp32ncp] TRACE: NCP event 1
0000002857 [ncp.at] TRACE: > AT+GETMAC=0
0000002878 [lu] INFO: Processing :11
0000002906 [ncp.at] TRACE: < +GETMAC: "30:ae:a4:d1:f7:cc"
0000002906 [ncp.at] TRACE: < OK
0000002907 [gsm0710muxer] INFO: Stopping GSM07.10 muxer
0000002911 [gsm0710muxer] INFO: Gracefully stopping GSM07.10 muxer
0000002923 [gsm0710muxer] INFO: Closing all muxed channels
0000002933 [gsm0710muxer] INFO: Closing mux channel 1
0000002946 [gsm0710muxer] INFO: Muxed channel 2 already closed
0000002955 [gsm0710muxer] INFO: Muxed channel 3 already closed
0000002968 [gsm0710muxer] INFO: Muxed channel 4 already closed
0000002978 [lu] INFO: Processing :12
0000003041 [lu] INFO: Processing :13
0000003078 [gsm0710muxer] INFO: Sending CLD (multiplexer close down)
0000003093 [lu] INFO: Processing :14
0000003128 [gsm0710muxer] INFO: Received response to CLD or timed out, exiting multiplexed mode
0000003128 [gsm0710muxer] INFO: GSM07.10 muxer thread exiting
0000003154 [gsm0710muxer] INFO: GSM07.10 muxer stopped
0000003155 [hal] TRACE: NCP state changed: 0
0000003155 [net.esp32ncp] TRACE: NCP event 1
0000003168 [lu] INFO: Processing :15
0000003219 [lu] INFO: Processing :16
0000003271 [lu] INFO: Processing :17
0000003323 [lu] INFO: Processing :18
0000003375 [lu] INFO: Processing :19
0000003428 [lu] INFO: Processing :20
0000003479 [lu] INFO: Processing :21
0000003531 [lu] INFO: Processing :22
0000003583 [lu] INFO: Processing :23
0000003635 [lu] INFO: Processing :24
0000003636 [lu] INFO: Processing :25
0000003688 [lu] INFO: Processing :26
0000003740 [lu] INFO: Processing :27
0000003792 [lu] INFO: Processing :28
0000003844 [lu] INFO: Processing :29
0000003896 [lu] INFO: Processing :30
0000003948 [lu] INFO: Processing :31
0000004000 [lu] INFO: Processing :32
0000004053 [lu] INFO: Processing :33
0000004104 [lu] INFO: Processing :34
0000004156 [lu] INFO: Processing :35
0000004208 [lu] INFO: Processing :36
0000004260 [lu] INFO: Processing :37
0000004312 [lu] INFO: Processing :38
0000004364 [lu] INFO: Processing :39
0000004416 [lu] INFO: Processing :40
0000004468 [lu] INFO: Processing :41
0000004520 [lu] INFO: Processing :42
0000004572 [lu] INFO: Processing :43
0000004624 [lu] INFO: Processing :44
0000004676 [lu] INFO: Processing :45
0000004728 [lu] INFO: Processing :46
0000004780 [lu] INFO: Processing :47
0000004832 [lu] INFO: Processing :48
0000004884 [lu] INFO: Processing :49
0000004936 [lu] INFO: Processing :50
0000004988 [lu] INFO: Processing :51
0000005040 [lu] INFO: Processing :52
0000005092 [lu] INFO: Processing :53
0000005093 [lu] INFO: Processing :54
0000005145 [lu] INFO: Processing :55
0000005146 [lu] INFO: Processing :56
0000005198 [lu] INFO: Processing :57
0000005250 [lu] INFO: Processing :58
0000005303 [lu] INFO: Processing :59
0000005354 [lu] INFO: Processing :60
0000005406 [lu] INFO: Processing :61
0000005458 [lu] INFO: Processing :62
0000005510 [lu] INFO: Processing :63
0000005511 [lu] INFO: Processing :64
0000005512 [lu] INFO: Processing :65
0000005563 [lu] INFO: Processing :66
0000005615 [lu] INFO: Processing :67
0000005616 [lu] INFO: Processing :68
0000005617 [lu] INFO: Processing :69
0000005668 [lu] INFO: Processing :70
0000005720 [lu] INFO: Processing :71
0000005772 [lu] INFO: Processing :72
0000005824 [lu] INFO: Processing :73
0000005876 [lu] INFO: Processing :74
0000005928 [lu] INFO: Processing :75
0000005980 [lu] INFO: Processing :76
0000006032 [lu] INFO: Processing :77
0000006084 [lu] INFO: Processing :78
0000006136 [lu] INFO: Processing :79
0000006137 [lu] INFO: Processing :80
0000006138 [lu] INFO: Processing :81
0000006189 [lu] INFO: Processing :82
0000006241 [lu] INFO: Processing :83
0000006293 [lu] INFO: Processing :84
0000006345 [lu] INFO: Processing :85
0000006397 [lu] INFO: Processing :86
0000006449 [lu] INFO: Processing :87
0000006501 [lu] INFO: Processing :88
0000006553 [lu] INFO: Processing :89
0000006605 [lu] INFO: Processing :90
0000006657 [lu] INFO: Processing :91
0000006709 [lu] INFO: Processing :92
0000006761 [lu] INFO: Processing :93
0000006813 [lu] INFO: Processing :94
0000006865 [lu] INFO: Processing :95
0000006917 [lu] INFO: Processing :96
0000006969 [lu] INFO: Processing :97
0000007021 [lu] INFO: Processing :98
0000007073 [lu] INFO: Processing :99
0000007125 [lu] INFO: Processing :100
0000007178 [lu] INFO: Processing :101
0000007229 [lu] INFO: Processing :102
0000007281 [lu] INFO: Processing :103
0000007333 [lu] INFO: Processing :104
0000007385 [lu] INFO: Processing :105
0000007437 [lu] INFO: Processing :106
0000007489 [lu] INFO: Processing :107
0000007541 [lu] INFO: Processing :108
0000007593 [lu] INFO: Processing :109
0000007645 [lu] INFO: Processing :110
0000007697 [lu] INFO: Processing :111
0000007749 [lu] INFO: Processing :112
0000007801 [lu] INFO: Processing :113
0000007853 [lu] INFO: Processing :114
0000007905 [lu] INFO: Processing :115
0000007906 [lu] INFO: Processing :116
0000007958 [lu] INFO: Processing :117
0000008010 [lu] INFO: Processing :118
0000008011 [lu] INFO: Processing :119
0000008063 [lu] INFO: Processing :120
0000008115 [lu] INFO: Processing :121
0000008167 [lu] INFO: Processing :122
0000008219 [lu] INFO: Processing :123
0000008220 [lu] INFO: Processing :124
0000008272 [lu] INFO: Processing :125
0000008324 [lu] INFO: Processing :126
0000008325 [lu] INFO: I2C devices at addr [19][36][38][40][41][44][45][50][51][74][77][7c]
0000008329 [lu] INFO: Finished scanning I2C bus
0000008340 [lu] INFO: Done Setup

Code with single_threaded_block

0000000272 [lu] INFO: Scanning I2C bus
0000000275 [lu] INFO: Processing :1
0000000277 [lu] INFO: Processing :2
0000000280 [lu] INFO: Processing :3
0000000288 [lu] INFO: Processing :4
0000000290 [lu] INFO: Processing :5
0000000297 [lu] INFO: Processing :6
0000000310 [lu] INFO: Processing :7
0000000313 [lu] INFO: Processing :8
0000000319 [lu] INFO: Processing :9
0000000321 [lu] INFO: Processing :10
0000000332 [lu] INFO: Processing :11
0000000335 [lu] INFO: Processing :12
0000000341 [lu] INFO: Processing :13
0000000355 [lu] INFO: Processing :14
0000000357 [lu] INFO: Processing :15
0000000364 [lu] INFO: Processing :16
0000000366 [lu] INFO: Processing :17
0000000377 [lu] INFO: Processing :18
0000000379 [lu] INFO: Processing :19
0000000386 [lu] INFO: Processing :20
0000000399 [lu] INFO: Processing :21
0000000402 [lu] INFO: Processing :22
0000000408 [lu] INFO: Processing :23
0000000421 [lu] INFO: Processing :24
0000000422 [lu] INFO: Processing :25
0000000430 [lu] INFO: Processing :26
0000000433 [lu] INFO: Processing :27
0000000444 [lu] INFO: Processing :28
0000000446 [lu] INFO: Processing :29
0000000453 [lu] INFO: Processing :30
0000000466 [lu] INFO: Processing :31
0000000468 [lu] INFO: Processing :32
0000000475 [lu] INFO: Processing :33
0000000488 [lu] INFO: Processing :34
0000000490 [lu] INFO: Processing :35
0000000497 [lu] INFO: Processing :36
0000000499 [lu] INFO: Processing :37
0000000510 [lu] INFO: Processing :38
0000000513 [lu] INFO: Processing :39
0000000519 [lu] INFO: Processing :40
0000000533 [lu] INFO: Processing :41
0000000535 [lu] INFO: Processing :42
0000000541 [lu] INFO: Processing :43
0000000555 [lu] INFO: Processing :44
0000000557 [lu] INFO: Processing :45
0000000560 [lu] INFO: Processing :46
0000000564 [lu] INFO: Processing :47
0000000577 [lu] INFO: Processing :48
0000000580 [lu] INFO: Processing :49
0000000586 [lu] INFO: Processing :50
0000000599 [lu] INFO: Processing :51
0000000602 [lu] INFO: Processing :52
0000000608 [lu] INFO: Processing :53
0000000609 [lu] INFO: Processing :54
0000000622 [lu] INFO: Processing :55
0000000622 [lu] INFO: Processing :56
0000000631 [lu] INFO: Processing :57
0000000644 [lu] INFO: Processing :58
0000000646 [lu] INFO: Processing :59
0000000653 [lu] INFO: Processing :60
0000000666 [lu] INFO: Processing :61
0000000668 [lu] INFO: Processing :62
0000000675 [lu] INFO: Processing :63
0000000675 [lu] INFO: Processing :64
0000000687 [lu] INFO: Processing :65
0000000689 [lu] INFO: Processing :66
0000000697 [lu] INFO: Processing :67
0000000709 [lu] INFO: Processing :68
0000000709 [lu] INFO: Processing :69
0000000719 [lu] INFO: Processing :70
0000000733 [lu] INFO: Processing :71
0000000735 [lu] INFO: Processing :72
0000000741 [lu] INFO: Processing :73
0000000744 [lu] INFO: Processing :74
0000000755 [lu] INFO: Processing :75
0000000757 [lu] INFO: Processing :76
0000000764 [lu] INFO: Processing :77
0000000777 [lu] INFO: Processing :78
0000000780 [lu] INFO: Processing :79
0000000784 [lu] INFO: Processing :80
0000000785 [lu] INFO: Processing :81
0000000800 [lu] INFO: Processing :82
0000000802 [lu] INFO: Processing :83
0000000809 [lu] INFO: Processing :84
0000000822 [lu] INFO: Processing :85
0000000824 [lu] INFO: Processing :86
0000000831 [lu] INFO: Processing :87
0000000844 [lu] INFO: Processing :88
0000000846 [lu] INFO: Processing :89
0000000853 [lu] INFO: Processing :90
0000000855 [lu] INFO: Processing :91
0000000866 [lu] INFO: Processing :92
0000000869 [lu] INFO: Processing :93
0000000875 [lu] INFO: Processing :94
0000000888 [lu] INFO: Processing :95
0000000891 [lu] INFO: Processing :96
0000000897 [lu] INFO: Processing :97
0000000911 [lu] INFO: Processing :98
0000000913 [lu] INFO: Processing :99
0000000919 [lu] INFO: Processing :100
0000000922 [lu] INFO: Processing :101
0000000933 [lu] INFO: Processing :102
0000000935 [lu] INFO: Processing :103
0000000942 [lu] INFO: Processing :104
0000000955 [lu] INFO: Processing :105
0000000958 [lu] INFO: Processing :106
0000000964 [lu] INFO: Processing :107
0000000977 [lu] INFO: Processing :108
0000000980 [lu] INFO: Processing :109
0000000986 [lu] INFO: Processing :110
0000000989 [lu] INFO: Processing :111
0000001000 [lu] INFO: Processing :112
0000001002 [lu] INFO: Processing :113
0000001009 [lu] INFO: Processing :114
0000001022 [lu] INFO: Processing :115
0000001022 [lu] INFO: Processing :116
0000001031 [lu] INFO: Processing :117
0000001044 [lu] INFO: Processing :118
0000001045 [lu] INFO: Processing :119
0000001053 [lu] INFO: Processing :120
0000001066 [lu] INFO: Processing :121
0000001069 [lu] INFO: Processing :122
0000001075 [lu] INFO: Processing :123
0000001076 [lu] INFO: Processing :124
0000001089 [lu] INFO: Processing :125
0000001091 [lu] INFO: Processing :126
0000001097 [lu] INFO: I2C devices at addr [19][36][38][40][41][44][45][50][51][74][77][7c]
0000001109 [lu] INFO: Finished scanning I2C bus
0000001118 [lu] INFO: Done Setup
0000002302 [ncp.at] TRACE: > AT
0000002303 [ncp.at] TRACE: < OK
0000003303 [hal] TRACE: NCP ready to accept AT commands
0000003303 [ncp.at] TRACE: > AT+CMUX=0
0000003305 [ncp.at] TRACE: < OK
0000003307 [gsm0710muxer] INFO: Starting GSM07.10 muxer
0000003329 [gsm0710muxer] INFO: Openning mux channel 0
0000003330 [gsm0710muxer] INFO: GSM07.10 muxer thread started
0000003402 [gsm0710muxer] INFO: Resuming channel 0
0000003402 [gsm0710muxer] INFO: Openning mux channel 1
0000003503 [gsm0710muxer] INFO: Resuming channel 1
0000003503 [gsm0710muxer] INFO: Resuming channel 1
0000003505 [ncp.at] TRACE: > AT
0000003556 [ncp.at] TRACE: < OK
0000003557 [ncp.at] TRACE: > AT+CWDHCP=0,3
0000003606 [ncp.at] TRACE: < OK
0000003606 [hal] TRACE: NCP state changed: 1
0000003607 [net.esp32ncp] TRACE: NCP event 1
0000003607 [ncp.at] TRACE: > AT+GETMAC=0
0000003656 [ncp.at] TRACE: < +GETMAC: "30:ae:a4:d1:f7:cc"
0000003656 [ncp.at] TRACE: < OK
0000003657 [gsm0710muxer] INFO: Stopping GSM07.10 muxer
0000003676 [gsm0710muxer] INFO: Gracefully stopping GSM07.10 muxer
0000003677 [gsm0710muxer] INFO: Closing all muxed channels
0000003699 [gsm0710muxer] INFO: Closing mux channel 1
0000003699 [gsm0710muxer] INFO: Muxed channel 2 already closed
0000003721 [gsm0710muxer] INFO: Muxed channel 3 already closed
0000003721 [gsm0710muxer] INFO: Muxed channel 4 already closed
0000003843 [gsm0710muxer] INFO: Sending CLD (multiplexer close down)
0000003893 [gsm0710muxer] INFO: Received response to CLD or timed out, exiting multiplexed mode
0000003893 [gsm0710muxer] INFO: GSM07.10 muxer thread exiting
0000003902 [gsm0710muxer] INFO: GSM07.10 muxer stopped
0000003920 [hal] TRACE: NCP state changed: 0
0000003920 [net.esp32ncp] TRACE: NCP event 1

What do you define as ‘boot’ - completing setup()? You seem to be doing an I2C bus scan in setup()?

My experience has been similar. From the time power is applied (or a reset), it takes far longer to get to breathing cyan mode. In my case, I’ve noticed this on an Argon, but haven’t really had the opportunity to view this on other model.