From 111461e5156407fd56daee971699f5c69b060b21 Mon Sep 17 00:00:00 2001 From: Deon George Date: Mon, 16 Aug 2021 00:41:43 +1000 Subject: [PATCH] Logging updates, some function optimisation --- app/Classes/File/Receive.php | 3 + app/Classes/Protocol.php | 63 +++++--- app/Classes/Protocol/Binkp.php | 218 ++++++++++++--------------- app/Classes/Protocol/EMSI.php | 21 +-- app/Classes/Sock/SocketServer.php | 6 +- app/Console/Commands/StartServer.php | 31 ++-- 6 files changed, 175 insertions(+), 167 deletions(-) diff --git a/app/Classes/File/Receive.php b/app/Classes/File/Receive.php index 6e157e4..5c12861 100644 --- a/app/Classes/File/Receive.php +++ b/app/Classes/File/Receive.php @@ -54,6 +54,9 @@ final class Receive extends Item case 'size': return $this->receiving ? $this->receiving->{'file_'.$key} : NULL; + case 'name_size_time': + return sprintf('%s %lu %lu',$this->name,$this->size,$this->mtime); + case 'to_get': return $this->list ->filter(function($item) { return ($item->action & self::I_RECV) && $item->received === FALSE; }) diff --git a/app/Classes/Protocol.php b/app/Classes/Protocol.php index cba7c4a..d71dcde 100644 --- a/app/Classes/Protocol.php +++ b/app/Classes/Protocol.php @@ -3,6 +3,7 @@ namespace App\Classes; use Exception; +use Illuminate\Support\Collection; use Illuminate\Support\Facades\Log; use App\Classes\File\{Receive,Send}; @@ -15,6 +16,8 @@ abstract class Protocol // Enable extra debugging protected bool $DEBUG = FALSE; + private const LOGKEY = 'P--'; + // Return constants protected const OK = 0; protected const EOF = -1; @@ -84,6 +87,7 @@ abstract class Protocol private array $comms; /* Our comms details */ abstract protected function protocol_init(): int; + abstract protected function protocol_session(): int; public function __construct(Setup $o=NULL) @@ -136,14 +140,14 @@ abstract class Protocol * * @throws Exception */ - protected function error_close(): void - { - if ($this->send->fd) - $this->send->close(FALSE); + protected function error_close(): void + { + if ($this->send->fd) + $this->send->close(FALSE); - if ($this->recv->fd) - $this->recv->close(); - } + if ($this->recv->fd) + $this->recv->close(); + } /** * Incoming Protocol session @@ -159,7 +163,7 @@ abstract class Protocol if ($pid == -1) throw new SocketException(SocketException::CANT_ACCEPT,'Could not fork process'); - Log::debug(sprintf('%s: = End [%d]',__METHOD__,$pid)); + Log::debug(sprintf('%s:= End [%d]',self::LOGKEY,$pid)); // Parent return ready for next connection return $pid; @@ -180,6 +184,31 @@ abstract class Protocol $this->options |= $key; } + /** + * Our addresses to send to the remote + * @return Collection + */ + protected function our_addresses(): Collection + { + if ($this->setup->optionGet(Setup::O_HIDEAKA)) { + $addresses = collect(); + + foreach ($this->node->aka_remote as $ao) + $addresses = $addresses->merge($this->setup->system->match($ao->zone)); + + $addresses = $addresses->unique(); + + Log::debug(sprintf('%s: - Presenting limited AKAs [%s]',self::LOGKEY,$addresses->pluck('ftn')->join(','))); + + } else { + $addresses = $this->setup->system->addresses; + + Log::debug(sprintf('%s: - Presenting ALL our AKAs [%s]',self::LOGKEY,$addresses->pluck('ftn')->join(','))); + } + + return $addresses; + } + /** * Initialise our Session * @@ -194,7 +223,7 @@ abstract class Protocol if ($o->exists) Log::withContext(['ftn'=>$o->address]); - Log::debug(sprintf('%s: + Start [%d]',__METHOD__,$type)); + Log::debug(sprintf('%s:+ Start [%d]',self::LOGKEY,$type)); // This sessions options $this->options = 0; @@ -226,36 +255,36 @@ abstract class Protocol switch ($type) { /** @noinspection PhpMissingBreakStatementInspection */ case self::SESSION_AUTO: - Log::debug(sprintf('%s: - Trying EMSI',__METHOD__)); + Log::debug(sprintf('%s: - Trying EMSI',self::LOGKEY)); $rc = $this->protocol_init(); if ($rc < 0) { - Log::error(sprintf('%s: ! Unable to start EMSI [%d]',__METHOD__,$rc)); + Log::error(sprintf('%s: ! Unable to start EMSI [%d]',self::LOGKEY,$rc)); return self::S_REDIAL | self::S_ADDTRY; } case self::SESSION_EMSI: - Log::debug(sprintf('%s: - Starting EMSI',__METHOD__)); + Log::debug(sprintf('%s: - Starting EMSI',self::LOGKEY)); $rc = $this->protocol_session(); break; case self::SESSION_BINKP: - Log::debug(sprintf('%s: - Starting BINKP',__METHOD__)); + Log::debug(sprintf('%s: - Starting BINKP',self::LOGKEY)); $rc = $this->protocol_session(); break; case self::SESSION_ZMODEM: - Log::debug(sprintf('%s: - Starting ZMODEM',__METHOD__)); + Log::debug(sprintf('%s: - Starting ZMODEM',self::LOGKEY)); $this->client->speed = SocketClient::TCP_SPEED; $this->originate = FALSE; return $this->protocol_session(); default: - Log::error(sprintf('%s: ! Unsupported session type [%d]',__METHOD__,$type)); + Log::error(sprintf('%s: ! Unsupported session type [%d]',self::LOGKEY,$type)); return self::S_REDIAL | self::S_ADDTRY; } @@ -273,8 +302,8 @@ abstract class Protocol if ($this->optionGet(self::O_HAT)) $rc |= self::S_HOLDA; - Log::info(sprintf('%s: Total: %s - %d:%02d:%02d online, (%d) %lu%s sent, (%d) %lu%s received - %s', - __METHOD__, + Log::info(sprintf('%s: Total: %s - %d:%02d:%02d online, (%d) %lu%s sent, (%d) %lu%s received - %s', + self::LOGKEY, $this->node->address->ftn, $this->node->session_time/3600, $this->node->session_time%3600/60, diff --git a/app/Classes/Protocol/Binkp.php b/app/Classes/Protocol/Binkp.php index a14da1c..a297aa7 100644 --- a/app/Classes/Protocol/Binkp.php +++ b/app/Classes/Protocol/Binkp.php @@ -2,7 +2,6 @@ namespace App\Classes\Protocol; -use App\Models\Setup; use Carbon\Carbon; use Exception; use Illuminate\Support\Arr; @@ -13,10 +12,12 @@ use League\Flysystem\UnreadableFileException; use App\Classes\Protocol as BaseProtocol; use App\Classes\Sock\SocketClient; use App\Classes\Sock\SocketException; -use App\Models\Address; +use App\Models\{Address,Setup}; final class Binkp extends BaseProtocol { + private const LOGKEY = 'PB-'; + /* -- */ private const BP_PROT = 'binkp'; /* protocol text */ private const BP_VERSION = '1.1'; /* version implemented */ @@ -101,9 +102,12 @@ final class Binkp extends BaseProtocol { // If our parent returns a PID, we've forked if (! parent::onConnect($client)) { + Log::withContext(['pid'=>getmypid()]); + $this->session(self::SESSION_BINKP,$client,(new Address)); $this->client->close(); - Log::info(sprintf('%s: = End - Connection closed [%s]',__METHOD__,$client->address_remote)); + + Log::info(sprintf('%s:= End - Connection closed [%s]',self::LOGKEY,$client->address_remote)); exit(0); } @@ -115,7 +119,8 @@ final class Binkp extends BaseProtocol */ private function binkp_hs(): void { - Log::debug(sprintf('%s: + Start',__METHOD__)); + if ($this->DEBUG) + Log::debug(sprintf('%s:+ binkp_hs',self::LOGKEY)); if (! $this->originate && ($this->setup->opt_md&self::O_WANT)) { $random_key = random_bytes(8); @@ -152,12 +157,12 @@ final class Binkp extends BaseProtocol $addresses = $addresses->unique(); - Log::debug(sprintf('%s: - Presenting limited AKAs [%s]',__METHOD__,$addresses->pluck('ftn')->join(','))); + Log::debug(sprintf('%s: - Presenting limited AKAs [%s]',self::LOGKEY,$addresses->pluck('ftn')->join(','))); } else { $addresses = $this->setup->system->addresses; - Log::debug(sprintf('%s: - Presenting ALL our AKAs [%s]',__METHOD__,$addresses->pluck('ftn')->join(','))); + Log::debug(sprintf('%s: - Presenting ALL our AKAs [%s]',self::LOGKEY,$addresses->pluck('ftn')->join(','))); } $this->msgs(self::BPM_ADR,$this->setup->system->addresses->pluck('ftn')->join(' ')); @@ -169,7 +174,8 @@ final class Binkp extends BaseProtocol */ private function binkp_hsdone(): int { - Log::debug(sprintf('%s: + Start',__METHOD__)); + if ($this->DEBUG) + Log::debug(sprintf('%s:+ binkp_hsdone',self::LOGKEY)); if (($this->setup->opt_nd == self::O_WE) || ($this->setup->opt_nd == self::O_THEY)) $this->setup->opt_nd = self::O_NO; @@ -204,7 +210,7 @@ final class Binkp extends BaseProtocol // We have no mechanism to support chat if ($this->setup->opt_cht&self::O_WANT) - Log::warning(sprintf('%s: - We cant do chat',__METHOD__)); + Log::warning(sprintf('%s: ! We cant do chat',self::LOGKEY)); if ($this->setup->opt_nd&self::O_WE || ($this->originate && ($this->setup->opt_nr&self::O_WANT) && $this->node->get_versionint() > 100)) $this->setup->opt_nr |= self::O_WE; @@ -220,8 +226,8 @@ final class Binkp extends BaseProtocol $this->mib = 0; $this->sessionClear(self::SE_INIT); - Log::info(sprintf('%s: - Session: BINKP/%d.%d - NR:%d, ND:%d, MD:%d, MB:%d, CR:%d, CHT:%d', - __METHOD__, + Log::info(sprintf('%s: - Session: BINKP/%d.%d - NR:%d, ND:%d, MD:%d, MB:%d, CR:%d, CHT:%d', + self::LOGKEY, $this->node->ver_major, $this->node->ver_minor, $this->setup->opt_nr, @@ -237,7 +243,8 @@ final class Binkp extends BaseProtocol private function binkp_init(): int { - Log::debug(sprintf('%s: + Start',__METHOD__)); + if ($this->DEBUG) + Log::debug(sprintf('%s:+ binkp_init',self::LOGKEY)); $this->sessionSet(self::SE_INIT); @@ -282,7 +289,7 @@ final class Binkp extends BaseProtocol break; default: - Log::error(sprintf('%s: ! Error - Unknown BINKP option [%s]',__METHOD__,$this->setup->binkp_options[$x])); + Log::error(sprintf('%s: ! binkp_init ERROR - Unknown BINKP option [%s]',self::LOGKEY,$this->setup->binkp_options[$x])); } } @@ -294,8 +301,7 @@ final class Binkp extends BaseProtocol */ private function binkp_recv(): int { - if ($this->DEBUG) - Log::debug(sprintf('%s: + Start',__METHOD__)); + Log::debug(sprintf('%s:+ binkp_recv',self::LOGKEY)); $buf = ''; $blksz = $this->rx_size == -1 ? BinkpMessage::BLK_HDR_SIZE : $this->rx_size; @@ -308,7 +314,7 @@ final class Binkp extends BaseProtocol if ($e->getCode() == 11) { // @todo We maybe should count these and abort if there are too many? if ($this->DEBUG) - Log::debug(sprintf('%s: - Socket EAGAIN',__METHOD__)); + Log::debug(sprintf('%s: - binkp_recv Socket EAGAIN',self::LOGKEY)); return 1; } @@ -321,7 +327,7 @@ final class Binkp extends BaseProtocol if (strlen($buf) == 0) { // @todo Check that this is correct. - Log::debug(sprintf('%s: - Was the socket closed by the remote?',__METHOD__)); + Log::debug(sprintf('%s: - binkp_recv Was the socket closed by the remote?',self::LOGKEY)); $this->error = -2; return 0; @@ -344,8 +350,7 @@ final class Binkp extends BaseProtocol $this->rx_size = ((ord(substr($buf,0,1))&0x7f) << 8 )+ord(substr($buf,1,1)); $this->rx_ptr = 0; - if ($this->DEBUG) - Log::debug(sprintf('%s: - HEADER, is_msg [%d]',__METHOD__,$this->is_msg)); + Log::debug(sprintf('%s: - binkp_recv HEADER, is_msg [%d]',self::LOGKEY,$this->is_msg)); if ($this->rx_size == 0) goto ZeroLen; @@ -355,28 +360,26 @@ final class Binkp extends BaseProtocol /* Next block */ } else { ZeroLen: - if ($this->DEBUG) - Log::debug(sprintf('%s: - NEXT BLOCK, is_msg [%d]',__METHOD__,$this->is_msg)); + Log::debug(sprintf('%s: - binkp_recv NEXT BLOCK, is_msg [%d]',self::LOGKEY,$this->is_msg)); if ($this->is_msg) { $this->mib++; /* Handle zero length block */ if ($this->rx_size == 0 ) { - Log::debug(sprintf('%s: - Zero length msg - dropped',__METHOD__)); + Log::debug(sprintf('%s: - binkp_recv Zero length msg - dropped',self::LOGKEY)); $this->rx_size = -1; $this->rx_ptr = 0; return 1; } - if ($this->DEBUG) - Log::debug(sprintf('%s: - BUFFER [%d]',__METHOD__,strlen($buf))); + Log::debug(sprintf('%s: - binkp_recv BUFFER [%d]',self::LOGKEY,strlen($buf))); $rc = ord(substr($buf,0,1)); if ($rc > self::BPM_MAX) { - Log::error(sprintf('%s: ! Unknown Message [%s] (%d)',__METHOD__,$buf,strlen($buf))); + Log::error(sprintf('%s: ! binkp_recv Unknown Message [%s] (%d)',self::LOGKEY,$buf,strlen($buf))); $rc = 1; } else { @@ -424,35 +427,34 @@ final class Binkp extends BaseProtocol break; default: - Log::error(sprintf('%s: ! Command not implemented [%d]',__METHOD__,$rc)); + Log::error(sprintf('%s: ! binkp_recv Command not implemented [%d]',self::LOGKEY,$rc)); $rc = 1; } } } else { - $tmp = sprintf('%s %lu %lu',$this->recv->name,$this->recv->size,$this->recv->mtime); // @todo move to Receive? - if ($this->recv->fd) { try { $rc = $this->recv->write($buf); } catch (Exception $e) { - Log::error(sprintf('%s: ! %s',__METHOD__,$e->getMessage())); + Log::error(sprintf('%s: ! %s',self::LOGKEY,$e->getMessage())); + $this->recv->close(); - $this->msgs(self::BPM_SKIP,$tmp); + $this->msgs(self::BPM_SKIP,$this->recv->name_size_time); $rc = 1; } if ($this->recv->filepos == $this->recv->size) { - Log::debug(sprintf('%s: - Finished receiving file [%s] with size [%d]',__METHOD__,$this->recv->name,$this->recv->size)); + Log::info(sprintf('%s: - Finished receiving file [%s] with size [%d]',self::LOGKEY,$this->recv->name,$this->recv->size)); $this->recv->close(); - $this->msgs(self::BPM_GOT,$tmp); + $this->msgs(self::BPM_GOT,$this->recv->name_size_time); $rc = 1; } } else { - Log::critical(sprintf('%s: - Ignoring data block', __METHOD__)); + Log::critical(sprintf('%s: - binkp_recv Ignoring data block', self::LOGKEY)); $rc = 1; } } @@ -465,8 +467,7 @@ final class Binkp extends BaseProtocol $rc = 1; } - if ($this->DEBUG) - Log::debug(sprintf('%s: = End [%d]',__METHOD__,$rc)); + Log::debug(sprintf('%s:= binkp_recv [%d]',self::LOGKEY,$rc)); return $rc; } @@ -476,14 +477,13 @@ final class Binkp extends BaseProtocol */ private function binkp_send(): int { - if ($this->DEBUG) - Log::debug(sprintf('%s: + Start - tx_left [%d]',__METHOD__,$this->tx_left)); + Log::debug(sprintf('%s:+ binkp_send - tx_left [%d]',self::LOGKEY,$this->tx_left)); if ($this->tx_left == 0 ) { /* tx buffer is empty */ $this->tx_ptr = $this->tx_left = 0; if ($this->DEBUG) - Log::debug(sprintf('%s: - Msgs [%d]',__METHOD__,$this->mqueue->count())); + Log::debug(sprintf('%s: - binkp_send msgs [%d]',self::LOGKEY,$this->mqueue->count())); if ($this->mqueue->count()) { /* there are unsent messages */ while ($msg = $this->mqueue->shift()) { @@ -506,7 +506,7 @@ final class Binkp extends BaseProtocol $this->sessionClear(self::SE_SENDFILE); } catch (Exception $e) { - Log::error(sprintf('%s: ! Unexpected ERROR [%s]',__METHOD__,$e->getMessage())); + Log::error(sprintf('%s: ! binkp_send unexpected ERROR [%s]',self::LOGKEY,$e->getMessage())); } if ($data) { @@ -538,7 +538,7 @@ final class Binkp extends BaseProtocol return 1; $this->socket_error = $e->getMessage(); - Log::error(sprintf('%s: ! Error [%s]',__METHOD__,$e->getMessage())); + Log::error(sprintf('%s:! binkp_send - ERROR [%s]',self::LOGKEY,$e->getMessage())); return 0; } @@ -551,15 +551,15 @@ final class Binkp extends BaseProtocol } } - if ($this->DEBUG) - Log::debug(sprintf('%s: = End [1]',__METHOD__)); + Log::debug(sprintf('%s:= binkp_send [1]',self::LOGKEY)); return 1; } private function file_parse(string $str): ?array { - Log::debug(sprintf('%s: + Start [%s]',__METHOD__,$str)); + if ($this->DEBUG) + Log::debug(sprintf('%s:+ file_parse [%s]',self::LOGKEY,$str)); $name = $this->strsep($str,' '); $size = $this->strsep($str,' '); @@ -585,7 +585,7 @@ final class Binkp extends BaseProtocol */ private function msgs(string $id,string $msg_body): void { - Log::debug(sprintf('%s: + Start [%s]',__METHOD__,$msg_body)); + Log::debug(sprintf('%s: msgs [%s]',self::LOGKEY,$msg_body)); $this->mqueue->push(new BinkpMessage($id,$msg_body)); @@ -603,23 +603,23 @@ final class Binkp extends BaseProtocol */ private function M_adr(string $buf): int { - Log::debug(sprintf('%s: + Start [%s]',__METHOD__,$buf)); + Log::debug(sprintf('%s:+ M_adr [%s]',self::LOGKEY,$buf)); $buf = $this->skip_blanks($buf); $rc = 0; while(($rem_aka = $this->strsep($buf,' '))) { - Log::info(sprintf('%s: - Parsing AKA [%s]',__METHOD__,$rem_aka)); + Log::info(sprintf('%s: - Parsing AKA [%s]',self::LOGKEY,$rem_aka)); try { if (! ($o = Address::findFTN($rem_aka))) { - Log::debug(sprintf('%s: ? AKA is UNKNOWN [%s]',__METHOD__,$rem_aka)); + Log::debug(sprintf('%s: ? AKA is UNKNOWN [%s]',self::LOGKEY,$rem_aka)); continue; } } catch (Exception) { - Log::error(sprintf('%s: ! AKA is INVALID [%s]',__METHOD__,$rem_aka)); + Log::error(sprintf('%s: ! AKA is INVALID [%s]',self::LOGKEY,$rem_aka)); $this->msgs(self::BPM_ERR,sprintf('Bad address %s',$rem_aka)); $this->rc = self::S_FAILURE; @@ -629,7 +629,7 @@ final class Binkp extends BaseProtocol // Check if the remote has our AKA if ($this->setup->system->addresses->pluck('ftn')->search($rem_aka) !== FALSE) { - Log::error(sprintf('%s: ! AKA is OURS [%s]',__METHOD__,$rem_aka)); + Log::error(sprintf('%s: ! AKA is OURS [%s]',self::LOGKEY,$rem_aka)); $this->msgs(self::BPM_ERR,sprintf('Sorry that is my AKA [%s]',$rem_aka)); $this->rc = self::S_FAILURE; @@ -644,7 +644,7 @@ final class Binkp extends BaseProtocol } if ($rc == 0) { - Log::error(sprintf('%s: ! All AKAs [%d] are busy',__METHOD__,$this->node->aka_num)); + Log::error(sprintf('%s: ! All AKAs [%d] are busy',self::LOGKEY,$this->node->aka_num)); $this->msgs( self::BPM_BSY,'All AKAs are busy'); $this->rc = ($this->originate ? self::S_REDIAL|self::S_ADDTRY : self::S_BUSY); @@ -654,7 +654,7 @@ final class Binkp extends BaseProtocol if ($this->originate) { if (! $this->node->originate_check()) { - Log::error(sprintf('%s: ! We didnt get who we called?',__METHOD__)); + Log::error(sprintf('%s: ! We didnt get who we called?',self::LOGKEY)); $this->msgs( self::BPM_ERR,'Sorry, you are not who I expected'); $this->rc = self::S_FAILURE|self::S_ADDTRY; @@ -682,38 +682,21 @@ final class Binkp extends BaseProtocol $this->optionSet(self::O_PWD); // If we are not the originator, we'll show our addresses in common. - if (! $this->originate) { - if ($this->setup->optionGet(Setup::O_HIDEAKA)) { - $addresses = collect(); - - foreach ($this->node->aka_remote as $ao) - $addresses = $addresses->merge($this->setup->system->match($ao->zone)); - - $addresses = $addresses->unique(); - - Log::debug(sprintf('%s: - Presenting limited AKAs [%s]',__METHOD__,$addresses->pluck('ftn')->join(','))); - - } else { - $addresses = $this->setup->system->addresses; - - Log::debug(sprintf('%s: - Presenting ALL our AKAs [%s]',__METHOD__,$addresses->pluck('ftn')->join(','))); - } - - $this->msgs(self::BPM_ADR,$addresses->pluck('ftn')->join(' ')); - } + if (! $this->originate) + $this->msgs(self::BPM_ADR,$this->our_addresses()->pluck('ftn')->join(' ')); return 1; } private function M_chat(string $buf): int { - Log::debug(sprintf('%s: + Start [%s]',__METHOD__,$buf)); + Log::debug(sprintf('%s:+ M_chat [%s]',self::LOGKEY,$buf)); if ($this->setup->opt_cht == self::O_YES) { - Log::error(sprintf('%s: - We cannot do chat',__METHOD__)); + Log::error(sprintf('%s: ! We cannot do chat',self::LOGKEY)); } else { - Log::error(sprintf('%s: - We got a chat message, but chat is disabled',__METHOD__)); + Log::error(sprintf('%s: ! We got a chat message, but chat is disabled',self::LOGKEY)); } return 1; @@ -726,7 +709,7 @@ final class Binkp extends BaseProtocol */ private function M_eob(string $buf): int { - Log::debug(sprintf('%s: + Start [%s]',__METHOD__,$buf)); + Log::debug(sprintf('%s:+ M_eob [%s]',self::LOGKEY,$buf)); if ($this->recv->fd) $this->recv->close(); @@ -738,7 +721,7 @@ final class Binkp extends BaseProtocol // Add our mail to the queue if we have authenticated if ($this->node->aka_authed) foreach ($this->node->aka_remote_authed as $ao) { - Log::debug(sprintf('%s: - Checking for any new mail to [%s]',__METHOD__,$ao->ftn)); + Log::debug(sprintf('%s: - M_eob Checking for any new mail to [%s]',self::LOGKEY,$ao->ftn)); $this->send->mail($ao); } @@ -754,10 +737,10 @@ final class Binkp extends BaseProtocol */ private function M_err(string $buf): int { - Log::debug(sprintf('%s: + Start [%s]',__METHOD__,$buf)); + Log::debug(sprintf('%s:+ M_err [%s]',self::LOGKEY,$buf)); $this->error_close(); - $this->rc = ($this->originate ? self::S_REDIAL|self::S_ADDTRY : self::S_BUSY); + $this->rc = ($this->originate ? (self::S_REDIAL|self::S_ADDTRY) : self::S_BUSY); return 0; } @@ -767,7 +750,7 @@ final class Binkp extends BaseProtocol */ private function M_file(string $buf): int { - Log::debug(sprintf('%s: + Start [%s]',__METHOD__,$buf)); + Log::debug(sprintf('%s:+ M_file [%s]',self::LOGKEY,$buf)); if ($this->sessionGet(self::SE_SENTEOB|self::SE_RECVEOB)) $this->sessionClear(self::SE_SENTEOB); @@ -778,7 +761,7 @@ final class Binkp extends BaseProtocol $this->recv->close(); if (! $file = $this->file_parse($buf)) { - Log::error(sprintf('%s: - UNPARSABLE file info [%s]',__METHOD__,$buf)); + Log::error(sprintf('%s: - UNPARSABLE file info [%s]',self::LOGKEY,$buf)); $this->msgs(self::BPM_ERR,sprintf('M_FILE: unparsable file info: "%s"',$buf)); if ($this->sessionGet(self::SE_SENDFILE)) @@ -805,22 +788,22 @@ final class Binkp extends BaseProtocol try { switch ($this->recv->open($this->node->address,$file['offs']<0)) { case self::FOP_ERROR: - Log::error(sprintf('%s: ! File Error',__METHOD__)); + Log::error(sprintf('%s: ! File ERROR',self::LOGKEY)); case self::FOP_SUSPEND: - Log::info(sprintf('%s: - File Suspended',__METHOD__)); - $this->msgs(self::BPM_SKIP, sprintf('%s %lu %lu',$this->recv->name,$this->recv->size,$this->recv->mtime)); + Log::info(sprintf('%s: - File Suspended',self::LOGKEY)); + $this->msgs(self::BPM_SKIP,$this->recv->name_size_time); break; case self::FOP_SKIP: - Log::info(sprintf('%s: - File Skipped',__METHOD__)); - $this->msgs(self::BPM_GOT,sprintf('%s %lu %lu',$this->recv->name,$this->recv->size,$this->recv->mtime)); + Log::info(sprintf('%s: - File Skipped',self::LOGKEY)); + $this->msgs(self::BPM_GOT,$this->recv->name_size_time); break; case self::FOP_OK: - Log::debug(sprintf('%s: - Getting file from [%d]',__METHOD__,$file['offs'])); + Log::debug(sprintf('%s: - Getting file from [%d]',self::LOGKEY,$file['offs'])); if ($file['offs'] != -1) { if (! ($this->setup->opt_nr&self::O_THEY)) { @@ -831,22 +814,17 @@ final class Binkp extends BaseProtocol } case self::FOP_CONT: - Log::debug(sprintf('%s: - Continuing file [%s] (%lu %lu %ld)',__METHOD__, - $this->recv->name,$this->recv->size,$this->recv->mtime,$file['offs'])); + Log::debug(sprintf('%s: - Continuing file [%s] (%ld)',self::LOGKEY,$this->recv->name,$file['offs'])); - $this->msgs(self::BPM_GET,sprintf('%s %lu %lu %ld', - $this->recv->name, - $this->recv->size, - $this->recv->mtime, - ($file['offs'] < 0) ? 0 : $file['offs'])); + $this->msgs(self::BPM_GET,sprintf('%s %ld',$this->recv->name_size_time,($file['offs'] < 0) ? 0 : $file['offs'])); break; } } catch (Exception $e) { - Log::error(sprintf('%s: ! File Open Error [%s]',__METHOD__,$e->getMessage())); + Log::error(sprintf('%s: ! File Open ERROR [%s]',self::LOGKEY,$e->getMessage())); - $this->msgs(self::BPM_SKIP,sprintf('%s %lu %lu',$this->recv->name,$this->recv->size,$this->recv->mtime)); + $this->msgs(self::BPM_SKIP,$this->recv->name_size_time); } return 1; @@ -857,7 +835,7 @@ final class Binkp extends BaseProtocol */ private function M_get(string $buf): int { - Log::debug(sprintf('%s: + Start [%s]',__METHOD__,$buf)); + Log::debug(sprintf('%s:+ M_get [%s]',self::LOGKEY,$buf)); if ($file = $this->file_parse($buf)) { if ($this->sessionGet(self::SE_SENDFILE) @@ -867,7 +845,7 @@ final class Binkp extends BaseProtocol && $this->send->size == Arr::get($file,'file.size')) { if (! $this->send->seek($file['offs'])) { - Log::error(sprintf('%s: ! Cannot send file from requested offset [%d]',__METHOD__,$file['offs'])); + Log::error(sprintf('%s: ! Cannot send file from requested offset [%d]',self::LOGKEY,$file['offs'])); $this->msgs(self::BPM_ERR,'Can\'t send file from requested offset'); $this->send->close(FALSE); @@ -879,11 +857,11 @@ final class Binkp extends BaseProtocol } } else { - Log::error(sprintf('%s: ! M_got for unknown file [%s]',__METHOD__,$buf)); + Log::error(sprintf('%s: ! M_got for unknown file [%s]',self::LOGKEY,$buf)); } } else { - Log::error(sprintf('%s: - UNPARSABLE file info [%s]',__METHOD__,$buf)); + Log::error(sprintf('%s: - UNPARSABLE file info [%s]',self::LOGKEY,$buf)); } return 1; @@ -898,7 +876,7 @@ final class Binkp extends BaseProtocol */ private function M_gotskip(string $buf):int { - Log::debug(sprintf('%s: + Start [%s]',__METHOD__,$buf)); + Log::debug(sprintf('%s:+ M_gotskip [%s]',self::LOGKEY,$buf)); if ($file = $this->file_parse($buf)) { if ($this->send->sendas @@ -918,12 +896,12 @@ final class Binkp extends BaseProtocol $this->send->close(TRUE); } else { - Log::error(sprintf('%s: ! M_got[skip] for unknown file [%s]',__METHOD__,$buf)); + Log::error(sprintf('%s: ! M_got[skip] for unknown file [%s]',self::LOGKEY,$buf)); } } } else { - Log::error(sprintf('%s: - UNPARSABLE file info [%s]',__METHOD__,$buf)); + Log::error(sprintf('%s: - UNPARSABLE file info [%s]',self::LOGKEY,$buf)); } return 1; @@ -934,7 +912,7 @@ final class Binkp extends BaseProtocol */ private function M_nul(string $buf): int { - Log::debug(sprintf('%s: + Start [%s]',__METHOD__,$buf)); + Log::debug(sprintf('%s:+ M_nul [%s]',self::LOGKEY,$buf)); if (! strncmp($buf,'SYS ',4)) { $this->node->system = $this->skip_blanks(substr($buf,4)); @@ -1034,7 +1012,7 @@ final class Binkp extends BaseProtocol } elseif (! strncmp($p,'CRAM-MD5-',9) && $this->originate && $this->setup->opt_md) { if (($x=strlen(substr($p,9))) > 64 ) { - Log::error(sprintf('%s: - Got TOO LONG [%d] challenge string',__METHOD__,$x)); + Log::error(sprintf('%s: - M_nul Got TOO LONG [%d] challenge string',self::LOGKEY,$x)); } else { $this->md_challenge = hex2bin(substr($p,9)); @@ -1047,14 +1025,14 @@ final class Binkp extends BaseProtocol $this->setup->opt_md = self::O_YES; } else { /* if ( strcmp( p, "GZ" ) || strcmp( p, "BZ2" ) || strcmp( p, "EXTCMD" )) */ - Log::warning(sprintf('%s: - Got UNSUPPORTED option [%s]',__METHOD__,$p)); + Log::warning(sprintf('%s: - M_nul Got UNSUPPORTED option [%s]',self::LOGKEY,$p)); } $data = substr($data,strpos($data,' ')); } } else { - Log::warning(sprintf('%s: - Got UNKNOWN NUL [%s]',__METHOD__,$buf)); + Log::warning(sprintf('%s: - M_nul Got UNKNOWN NUL [%s]',self::LOGKEY,$buf)); } return 1; @@ -1067,10 +1045,10 @@ final class Binkp extends BaseProtocol */ private function M_ok(string $buf): int { - Log::debug(sprintf('%s: + Start [%s]',__METHOD__,$buf)); + Log::debug(sprintf('%s:+ M_ok [%s]',self::LOGKEY,$buf)); if (! $this->originate) { - Log::error(sprintf('%s: ! UNEXPECTED M_OK [%s] from remote on incoming call',__METHOD__,$buf)); + Log::error(sprintf('%s: ! UNEXPECTED M_OK [%s] from remote on incoming call',self::LOGKEY,$buf)); $this->rc = self::S_FAILURE; return 0; @@ -1081,7 +1059,7 @@ final class Binkp extends BaseProtocol if ($this->optionGet(self::O_PWD) && $buf) { while (($t = $this->strsep($buf," \t"))) if (strcmp($t,'non-secure') == 0) { - Log::debug(sprintf('%s: - Non Secure',__METHOD__)); + Log::debug(sprintf('%s: - Non Secure',self::LOGKEY)); $this->setup->opt_cr = self::O_NO; $this->optionClear(self::O_PWD); @@ -1098,7 +1076,7 @@ final class Binkp extends BaseProtocol $this->msgs(self::BPM_NUL,sprintf('TRF %lu %lu',$this->send->mail_size,$this->send->file_size)); - Log::debug(sprintf('%s: = End',__METHOD__)); + Log::debug(sprintf('%s:= End',self::LOGKEY)); return $this->binkp_hsdone(); } @@ -1107,14 +1085,14 @@ final class Binkp extends BaseProtocol */ private function M_pwd(string $buf): int { - Log::debug(sprintf('%s: + Start [%s]',__METHOD__,$buf)); + Log::debug(sprintf('%s:+ M_pwd [%s]',self::LOGKEY,$buf)); $buf = $this->skip_blanks($buf); $have_CRAM = !strncasecmp($buf,'CRAM-MD5-',9); $have_pwd = $this->optionGet(self::O_PWD); if ($this->originate) { - Log::error(sprintf('%s: ! Unexpected password [%s] from remote on OUTGOING call',__METHOD__,$buf)); + Log::error(sprintf('%s: ! Unexpected password [%s] from remote on OUTGOING call',self::LOGKEY,$buf)); $this->rc = self::S_FAILURE; return 0; @@ -1127,7 +1105,7 @@ final class Binkp extends BaseProtocol $this->setup->opt_md |= self::O_THEY; } elseif ($this->setup->opt_md&self::O_NEED) { - Log::error(sprintf('%s: ! Remote doesnt support MD5',__METHOD__)); + Log::error(sprintf('%s: ! Remote doesnt support MD5',self::LOGKEY)); $this->msgs( self::BPM_ERR,'You must support MD5'); $this->rc = self::S_FAILURE; @@ -1144,7 +1122,7 @@ final class Binkp extends BaseProtocol if ($have_pwd) { // If no passwords matched (ie: aka_authed is 0) if (! $this->node->aka_authed) { - Log::error(sprintf('%s: ! Bad password [%s]',__METHOD__,$buf)); + Log::error(sprintf('%s: ! Bad password [%s]',self::LOGKEY,$buf)); $this->msgs(self::BPM_ERR,'Security violation'); $this->optionSet(self::O_BAD); @@ -1154,7 +1132,7 @@ final class Binkp extends BaseProtocol } } elseif (! $this->node->aka_authed) { - Log::notice(sprintf('%s: - Remote proposed password for us [%s]',__METHOD__,$buf)); + Log::notice(sprintf('%s: - Remote proposed password for us [%s]',self::LOGKEY,$buf)); } if (($this->setup->opt_md&(self::O_THEY|self::O_WANT )) == (self::O_THEY|self::O_WANT)) @@ -1189,6 +1167,7 @@ final class Binkp extends BaseProtocol protected function protocol_init(): int { // Not Used + return 0; } /** @@ -1199,7 +1178,7 @@ final class Binkp extends BaseProtocol */ protected function protocol_session(): int { - Log::debug(sprintf('%s: + Start',__METHOD__)); + Log::debug(sprintf('%s:+ protocol_session',self::LOGKEY)); if ($this->binkp_init() != self::OK) return $this->originate ? (self::S_REDIAL|self::S_ADDTRY) : self::S_FAILURE; @@ -1218,7 +1197,7 @@ final class Binkp extends BaseProtocol if ($this->setup->opt_nr&self::O_WE) { $this->sessionSet(self::SE_WAITGET); - Log::debug(sprintf('%s: - Waiting for M_GET',__METHOD__)); + Log::debug(sprintf('%s: - Waiting for M_GET',self::LOGKEY)); } $this->msgs(self::BPM_FILE, @@ -1278,10 +1257,10 @@ final class Binkp extends BaseProtocol } if ($this->error == -1) - Log::error(sprintf('%s: ! TIMEOUT',__METHOD__)); + Log::error(sprintf('%s: ! protocol_session TIMEOUT',self::LOGKEY)); elseif ($this->error > 0) - Log::error(sprintf('%s: ! Got ERROR [%d]',__METHOD__,$this->socket_error)); + Log::error(sprintf('%s: ! protocol_session Got ERROR [%d]',self::LOGKEY,$this->socket_error)); while (! $this->error) { try { @@ -1289,7 +1268,7 @@ final class Binkp extends BaseProtocol } catch (Exception $e) { if ($e->getCode() !== 11) { - Log::debug(sprintf('%s: ? Got Exception [%d] (%s)',__METHOD__,$e->getCode(),$e->getMessage())); + Log::debug(sprintf('%s: ? protocol_session Got Exception [%d] (%s)',self::LOGKEY,$e->getCode(),$e->getMessage())); $this->error = 1; } @@ -1300,7 +1279,7 @@ final class Binkp extends BaseProtocol if (strlen($buf) == 0) break; - Log::warning(sprintf('%s: - Purged (%s) [%d] bytes from input stream',__METHOD__,serialize($buf),strlen($buf))); + Log::warning(sprintf('%s: - Purged (%s) [%d] bytes from input stream',self::LOGKEY,serialize($buf),strlen($buf))); } while (! $this->error && ($this->mqueue->count() || $this->tx_left) && $this->binkp_send()); @@ -1356,4 +1335,3 @@ final class Binkp extends BaseProtocol return $str && in_array($str,[' ',"\n","\r","\v","\f","\t"]); } } - diff --git a/app/Classes/Protocol/EMSI.php b/app/Classes/Protocol/EMSI.php index 4154cd7..a2da778 100644 --- a/app/Classes/Protocol/EMSI.php +++ b/app/Classes/Protocol/EMSI.php @@ -21,6 +21,8 @@ final class EMSI extends BaseProtocol implements CRCInterface,ZmodemInterface { use CRCTrait; + private const LOGKEY = 'PE-'; + private const EMSI_BEG = '**EMSI_'; private const EMSI_ARGUS1 = '-PZT8AF6-'; private const EMSI_DAT = self::EMSI_BEG.'DAT'; @@ -181,26 +183,9 @@ final class EMSI extends BaseProtocol implements CRCInterface,ZmodemInterface // @todo We need to evaluate what the remote presents $compat_codes = $this->originate ? ['ZMO','ARC','XMA'] : ['ZMO']; - // Only show our AKAs relevant to the site we are ccmmunicating with - if ($this->setup->optionGet(Setup::O_HIDEAKA)) { - $addresses = collect(); - - foreach ($this->node->aka_remote as $ao) - $addresses = $addresses->merge($this->setup->system->match($ao->zone)); - - $addresses = $addresses->unique(); - - Log::debug(sprintf('%s: - Presenting limited AKAs [%s]',__METHOD__,$addresses->pluck('ftn')->join(','))); - - } else { - $addresses = $this->setup->system->addresses; - - Log::debug(sprintf('%s: - Presenting ALL our AKAs [%s]',__METHOD__,$addresses->pluck('ftn')->join(','))); - } - // Site address, password and compatibility $makedata .= sprintf('{EMSI}{%s}{%s}{%s}{%s}', - $addresses->pluck('ftn')->join(' '), + $this->our_addresses()->pluck('ftn')->join(' '), $this->node->password == '-' ? '' : $this->node->password, join(',',$link_codes), join(',',$compat_codes), diff --git a/app/Classes/Sock/SocketServer.php b/app/Classes/Sock/SocketServer.php index a5fb7e0..2930722 100644 --- a/app/Classes/Sock/SocketServer.php +++ b/app/Classes/Sock/SocketServer.php @@ -5,6 +5,8 @@ namespace App\Classes\Sock; use Illuminate\Support\Facades\Log; final class SocketServer { + private const LOGKEY = 'SS-'; + private $server; // Our server resource private string $bind; // The IP address to bind to private int $port; // The Port to bind to @@ -79,12 +81,12 @@ final class SocketServer { if (socket_listen($this->server,$this->backlog) === FALSE) throw new SocketException(SocketException::CANT_LISTEN,socket_strerror(socket_last_error($this->server))); - Log::info(sprintf('Listening on [%s:%d]',$this->bind,$this->port),['m'=>__METHOD__]); + Log::info(sprintf('%s:- Listening on [%s:%d]',self::LOGKEY,$this->bind,$this->port)); $this->loop(); socket_close($this->server); - Log::info(sprintf('Closed [%s:%d]',$this->bind,$this->port),['m'=>__METHOD__]); + Log::info(sprintf('%s:= Closed [%s:%d]',self::LOGKEY,$this->bind,$this->port)); } /** diff --git a/app/Console/Commands/StartServer.php b/app/Console/Commands/StartServer.php index 36531aa..fe11aaa 100644 --- a/app/Console/Commands/StartServer.php +++ b/app/Console/Commands/StartServer.php @@ -12,6 +12,8 @@ use App\Models\Setup; class StartServer extends Command { + private const LOGKEY = 'CSS'; + /** * The name and signature of the console command. * @@ -26,6 +28,13 @@ class StartServer extends Command */ protected $description = 'Start Server'; + public function __construct() + { + parent::__construct(); + + Log::info(sprintf('%s:+ Server Starting (%d)',self::LOGKEY,getmypid())); + } + /** * Execute the console command. * @@ -54,17 +63,17 @@ class StartServer extends Command $children = collect(); - Log::debug(sprintf('%s:+ Starting Servers...',__METHOD__)); + Log::debug(sprintf('%s: # Servers [%d]',self::LOGKEY,$start->count())); if (! $start->count()) { - Log::alert(sprintf('%s: - No servers configured to start',__METHOD__)); + Log::alert(sprintf('%s:- No servers configured to start',self::LOGKEY)); return; } pcntl_signal(SIGCHLD,SIG_IGN); - foreach ($start->toArray() as $item => $config) { - Log::debug(sprintf('%s: - Starting: [%s]',__METHOD__,$item)); + foreach ($start as $item => $config) { + Log::debug(sprintf('%s: - Starting [%s] (%d)',self::LOGKEY,$item,getmypid())); $pid = pcntl_fork(); @@ -73,7 +82,8 @@ class StartServer extends Command // We are the child if (! $pid) { - Log::info(sprintf('%s: - Started: [%s]',__METHOD__,$item)); + Log::withContext(['pid'=>getmypid()]); + Log::info(sprintf('%s: - Started [%s]',self::LOGKEY,$item)); $server = new SocketServer($config['port'],$config['address']); $server->setConnectionHandler([$config['class'],'onConnect']); @@ -83,17 +93,18 @@ class StartServer extends Command } catch (SocketException $e) { if ($e->getMessage() == 'Can\'t accept connections: "Success"') - Log::debug('Server Terminated'); + Log::debug(sprintf('%s:! Server Terminated [%s]',self::LOGKEY,$item)); else - Log::emergency('Uncaught Message: '.$e->getMessage()); + Log::emergency(sprintf('%s:! Uncaught Message: %s',self::LOGKEY,$e->getMessage())); } - Log::info(sprintf('%s: - Finished: [%s]',__METHOD__,$item)); + Log::info(sprintf('%s: - Finished: [%s]',self::LOGKEY,$item)); // Child finished we need to get out of this loop. exit; } + Log::info(sprintf('%s: - Forked for [%s] (%d)',self::LOGKEY,$item,$pid)); $children->put($pid,$item); } @@ -105,10 +116,10 @@ class StartServer extends Command if ($exited < 0) abort(500,'Something strange for status: '.serialize($status)); - Log::info(sprintf('%s: - Exited: #%d [%s]',__METHOD__,$x,$children->pull($exited))); + Log::info(sprintf('%s: - Exited: #%d [%s]',self::LOGKEY,$x,$children->pull($exited))); } // Done - Log::debug(sprintf('%s: = Finished.',__METHOD__)); + Log::debug(sprintf('%s:= Finished.',self::LOGKEY)); } }