executor.go 28 KB

12345678910111213141516171819202122232425262728293031323334353637383940414243444546474849505152535455565758596061626364656667686970717273747576777879808182838485868788899091929394959697989910010110210310410510610710810911011111211311411511611711811912012112212312412512612712812913013113213313413513613713813914014114214314414514614714814915015115215315415515615715815916016116216316416516616716816917017117217317417517617717817918018118218318418518618718818919019119219319419519619719819920020120220320420520620720820921021121221321421521621721821922022122222322422522622722822923023123223323423523623723823924024124224324424524624724824925025125225325425525625725825926026126226326426526626726826927027127227327427527627727827928028128228328428528628728828929029129229329429529629729829930030130230330430530630730830931031131231331431531631731831932032132232332432532632732832933033133233333433533633733833934034134234334434534634734834935035135235335435535635735835936036136236336436536636736836937037137237337437537637737837938038138238338438538638738838939039139239339439539639739839940040140240340440540640740840941041141241341441541641741841942042142242342442542642742842943043143243343443543643743843944044144244344444544644744844945045145245345445545645745845946046146246346446546646746846947047147247347447547647747847948048148248348448548648748848949049149249349449549649749849950050150250350450550650750850951051151251351451551651751851952052152252352452552652752852953053153253353453553653753853954054154254354454554654754854955055155255355455555655755855956056156256356456556656756856957057157257357457557657757857958058158258358458558658758858959059159259359459559659759859960060160260360460560660760860961061161261361461561661761861962062162262362462562662762862963063163263363463563663763863964064164264364464564664764864965065165265365465565665765865966066166266366466566666766866967067167267367467567667767867968068168268368468568668768868969069169269369469569669769869970070170270370470570670770870971071171271371471571671771871972072172272372472572672772872973073173273373473573673773873974074174274374474574674774874975075175275375475575675775875976076176276376476576676776876977077177277377477577677777877978078178278378478578678778878979079179279379479579679779879980080180280380480580680780880981081181281381481581681781881982082182282382482582682782882983083183283383483583683783883984084184284384484584684784884985085185285385485585685785885986086186286386486586686786886987087187287387487587687787887988088188288388488588688788888989089189289389489589689789889990090190290390490590690790890991091191291391491591691791891992092192292392492592692792892993093193293393493593693793893994094194294394494594694794894995095195295395495595695795895996096196296396496596696796896997097197297397497597697797897998098198298398498598698798898999099199299399499599699799899910001001100210031004100510061007100810091010101110121013101410151016101710181019102010211022102310241025102610271028
  1. package executor
  2. import (
  3. acl "github.com/OliveTin/OliveTin/internal/acl"
  4. "github.com/OliveTin/OliveTin/internal/auth"
  5. authpublic "github.com/OliveTin/OliveTin/internal/auth/authpublic"
  6. config "github.com/OliveTin/OliveTin/internal/config"
  7. "github.com/OliveTin/OliveTin/internal/entities"
  8. "github.com/OliveTin/OliveTin/internal/tpl"
  9. "github.com/google/uuid"
  10. log "github.com/sirupsen/logrus"
  11. "github.com/prometheus/client_golang/prometheus"
  12. "github.com/prometheus/client_golang/prometheus/promauto"
  13. "gopkg.in/yaml.v3"
  14. "bytes"
  15. "context"
  16. "fmt"
  17. "os"
  18. "os/exec"
  19. "path"
  20. "strings"
  21. "sync"
  22. "time"
  23. )
  24. const (
  25. DefaultExitCodeNotExecuted = -1337
  26. MaxTriggerDepth = 10
  27. )
  28. var (
  29. metricActionsRequested = promauto.NewCounter(prometheus.CounterOpts{
  30. Name: "olivetin_actions_requested_count",
  31. Help: "The actions requested count",
  32. })
  33. )
  34. type ActionBinding struct {
  35. ID string
  36. Action *config.Action
  37. Entity *entities.Entity
  38. ConfigOrder int
  39. IsOnDashboard bool
  40. }
  41. // Executor represents a helper class for executing commands. It's main method
  42. // is ExecRequest
  43. type Executor struct {
  44. logs map[string]*InternalLogEntry
  45. logsTrackingIdsByDate []string
  46. LogsByBindingId map[string][]*InternalLogEntry
  47. logmutex sync.RWMutex
  48. MapActionBindings map[string]*ActionBinding
  49. MapActionBindingsLock sync.RWMutex
  50. Cfg *config.Config
  51. listeners []listener
  52. chainOfCommand []executorStepFunc
  53. }
  54. // ExecutionRequest is a request to execute an action. It's passed to an
  55. // Executor. They're created from the api.
  56. type ExecutionRequest struct {
  57. Binding *ActionBinding
  58. Arguments map[string]string
  59. TrackingID string
  60. Tags []string
  61. Cfg *config.Config
  62. AuthenticatedUser *authpublic.AuthenticatedUser
  63. TriggerDepth int
  64. logEntry *InternalLogEntry
  65. finalParsedCommand string
  66. execArgs []string
  67. useDirectExec bool
  68. executor *Executor
  69. }
  70. // InternalLogEntry objects are created by an Executor, and represent the final
  71. // state of execution (even if the command is not executed). It's designed to be
  72. // easily serializable.
  73. type InternalLogEntry struct {
  74. Binding *ActionBinding
  75. DatetimeStarted time.Time
  76. DatetimeFinished time.Time
  77. Output string
  78. TimedOut bool
  79. Blocked bool
  80. ExitCode int32
  81. Tags []string
  82. ExecutionStarted bool
  83. ExecutionFinished bool
  84. ExecutionTrackingID string
  85. Process *os.Process
  86. Username string
  87. Index int64
  88. EntityPrefix string
  89. ActionConfigTitle string // This is the title of the action as defined in the config, not the final parsed title.
  90. /*
  91. The following 3 properties are obviously on Action normally, but it's useful
  92. that logs are lightweight (so we don't need to have an action associated to
  93. logs, etc. Therefore, we duplicate those values here.
  94. */
  95. ActionTitle string
  96. ActionIcon string
  97. }
  98. type executorStepFunc func(*ExecutionRequest) bool
  99. // DefaultExecutor returns an Executor, with a sensible "chain of command" for
  100. // executing actions.
  101. func DefaultExecutor(cfg *config.Config) *Executor {
  102. e := Executor{}
  103. e.Cfg = cfg
  104. e.logs = make(map[string]*InternalLogEntry)
  105. e.logsTrackingIdsByDate = make([]string, 0)
  106. e.LogsByBindingId = make(map[string][]*InternalLogEntry)
  107. e.MapActionBindings = make(map[string]*ActionBinding)
  108. e.chainOfCommand = []executorStepFunc{
  109. stepRequestAction,
  110. stepConcurrencyCheck,
  111. stepRateCheck,
  112. stepACLCheck,
  113. stepParseArgs,
  114. stepLogStart,
  115. stepExec,
  116. stepExecAfter,
  117. stepLogFinish,
  118. stepSaveLog,
  119. stepTrigger,
  120. }
  121. return &e
  122. }
  123. type listener interface {
  124. OnExecutionStarted(logEntry *InternalLogEntry)
  125. OnExecutionFinished(logEntry *InternalLogEntry)
  126. OnOutputChunk(o []byte, executionTrackingId string)
  127. OnActionMapRebuilt()
  128. }
  129. func (e *Executor) AddListener(m listener) {
  130. e.listeners = append(e.listeners, m)
  131. }
  132. // getPagingStartIndex calculates the starting index for log pagination.
  133. // Parameters:
  134. //
  135. // startOffset: The offset from the most recent log (0 means start from the most recent)
  136. // totalLogCount: Total number of logs available
  137. // count: Number of logs to retrieve
  138. //
  139. // Returns: The calculated starting index for pagination
  140. func getPagingStartIndex(startOffset int64, totalLogCount int64) int64 {
  141. var startIndex int64
  142. if startOffset <= 0 {
  143. startIndex = totalLogCount
  144. } else {
  145. startIndex = (totalLogCount - startOffset)
  146. if startIndex < 0 {
  147. startIndex = 1
  148. }
  149. }
  150. return startIndex - 1
  151. }
  152. type PagingResult struct {
  153. CountRemaining int64
  154. PageSize int64
  155. TotalCount int64
  156. StartOffset int64
  157. }
  158. func (e *Executor) GetLogTrackingIds(startOffset int64, pageCount int64) ([]*InternalLogEntry, *PagingResult) {
  159. pagingResult := &PagingResult{
  160. CountRemaining: 0,
  161. PageSize: pageCount,
  162. TotalCount: 0,
  163. StartOffset: startOffset,
  164. }
  165. e.logmutex.RLock()
  166. totalLogCount := int64(len(e.logsTrackingIdsByDate))
  167. pagingResult.TotalCount = totalLogCount
  168. startIndex := getPagingStartIndex(startOffset, totalLogCount)
  169. pageCount = min(totalLogCount, pageCount)
  170. endIndex := max(0, (startIndex-pageCount)+1)
  171. log.WithFields(log.Fields{
  172. "startOffset": startOffset,
  173. "pageCount": pageCount,
  174. "total": totalLogCount,
  175. "startIndex": startIndex,
  176. "endIndex": endIndex,
  177. }).Tracef("GetLogTrackingIds")
  178. trackingIds := make([]*InternalLogEntry, 0, pageCount)
  179. if totalLogCount > 0 {
  180. for i := endIndex; i <= startIndex; i++ {
  181. trackingIds = append(trackingIds, e.logs[e.logsTrackingIdsByDate[i]])
  182. }
  183. }
  184. e.logmutex.RUnlock()
  185. pagingResult.CountRemaining = endIndex
  186. return trackingIds, pagingResult
  187. }
  188. func isValidLogEntryForACL(entry *InternalLogEntry) bool {
  189. return entry != nil && entry.Binding != nil && entry.Binding.Action != nil
  190. }
  191. func isLogEntryAllowedByACL(cfg *config.Config, user *authpublic.AuthenticatedUser, entry *InternalLogEntry) bool {
  192. return acl.IsAllowedLogs(cfg, user, entry.Binding.Action)
  193. }
  194. func (e *Executor) filterLogsByACL(cfg *config.Config, user *authpublic.AuthenticatedUser, dateFilter string) []*InternalLogEntry {
  195. e.logmutex.RLock()
  196. defer e.logmutex.RUnlock()
  197. filtered := make([]*InternalLogEntry, 0, len(e.logsTrackingIdsByDate))
  198. filterDate, hasDateFilter := parseDateFilter(dateFilter)
  199. for _, trackingId := range e.logsTrackingIdsByDate {
  200. entry := e.logs[trackingId]
  201. if shouldIncludeLogEntry(cfg, user, entry, filterDate, hasDateFilter) {
  202. filtered = append(filtered, entry)
  203. }
  204. }
  205. return filtered
  206. }
  207. // parseDateFilter parses the date filter string and returns filter information.
  208. func parseDateFilter(dateFilter string) (filterDate time.Time, hasDateFilter bool) {
  209. if dateFilter == "" {
  210. return time.Time{}, false
  211. }
  212. parsedDate, err := time.Parse("2006-01-02", dateFilter)
  213. if err != nil {
  214. log.WithFields(log.Fields{
  215. "dateFilter": dateFilter,
  216. "error": err,
  217. }).Errorf("Failed to parse date filter, expected format YYYY-MM-DD")
  218. return time.Time{}, false
  219. }
  220. return parsedDate, true
  221. }
  222. // shouldIncludeLogEntry determines if a log entry should be included based on ACL and date filter.
  223. func shouldIncludeLogEntry(cfg *config.Config, user *authpublic.AuthenticatedUser, entry *InternalLogEntry, filterDate time.Time, hasDateFilter bool) bool {
  224. if !isValidLogEntryForACL(entry) {
  225. return false
  226. }
  227. if !isLogEntryAllowedByACL(cfg, user, entry) {
  228. return false
  229. }
  230. return matchesDateFilter(entry, filterDate, hasDateFilter)
  231. }
  232. // matchesDateFilter checks if the log entry matches the date filter.
  233. func matchesDateFilter(entry *InternalLogEntry, filterDate time.Time, hasDateFilter bool) bool {
  234. if !hasDateFilter {
  235. return true
  236. }
  237. entryDate := entry.DatetimeStarted.UTC().Truncate(24 * time.Hour)
  238. filterDateUTC := filterDate.UTC().Truncate(24 * time.Hour)
  239. return entryDate.Equal(filterDateUTC)
  240. }
  241. // paginateFilteredLogs applies pagination to a filtered list of logs and returns
  242. // the paginated results along with pagination metadata.
  243. func paginateFilteredLogs(filtered []*InternalLogEntry, startOffset int64, pageCount int64) ([]*InternalLogEntry, *PagingResult) {
  244. total := int64(len(filtered))
  245. paging := &PagingResult{PageSize: pageCount, TotalCount: total, StartOffset: startOffset}
  246. if total == 0 {
  247. paging.CountRemaining = 0
  248. return []*InternalLogEntry{}, paging
  249. }
  250. startIndex := getPagingStartIndex(startOffset, total)
  251. pageCount = min(total, pageCount)
  252. endIndex := max(0, (startIndex-pageCount)+1)
  253. out := make([]*InternalLogEntry, 0, pageCount)
  254. for i := endIndex; i <= startIndex && i < int64(len(filtered)); i++ {
  255. out = append(out, filtered[i])
  256. }
  257. paging.CountRemaining = endIndex
  258. return out, paging
  259. }
  260. // GetLogTrackingIdsACL returns logs filtered by ACL visibility for the user and
  261. // paginated correctly based on the filtered set.
  262. // dateFilter is optional and should be in YYYY-MM-DD format. If empty, no date filtering is applied.
  263. func (e *Executor) GetLogTrackingIdsACL(cfg *config.Config, user *authpublic.AuthenticatedUser, startOffset int64, pageCount int64, dateFilter string) ([]*InternalLogEntry, *PagingResult) {
  264. filtered := e.filterLogsByACL(cfg, user, dateFilter)
  265. return paginateFilteredLogs(filtered, startOffset, pageCount)
  266. }
  267. func (e *Executor) GetLog(trackingID string) (*InternalLogEntry, bool) {
  268. e.logmutex.RLock()
  269. entry, found := e.logs[trackingID]
  270. e.logmutex.RUnlock()
  271. return entry, found
  272. }
  273. func (e *Executor) GetLogsByBindingId(bindingId string) []*InternalLogEntry {
  274. e.logmutex.RLock()
  275. logs, found := e.LogsByBindingId[bindingId]
  276. e.logmutex.RUnlock()
  277. if !found {
  278. return make([]*InternalLogEntry, 0)
  279. }
  280. return logs
  281. }
  282. // shouldCountExecution checks if a log entry should be counted for rate limiting.
  283. func shouldCountExecution(logEntry *InternalLogEntry, windowStart time.Time) bool {
  284. return !logEntry.Blocked && logEntry.DatetimeStarted.After(windowStart)
  285. }
  286. // updateOldestExecution updates the oldest execution time if this entry is older.
  287. func updateOldestExecution(oldestExecutionTime **time.Time, logEntry *InternalLogEntry) {
  288. if *oldestExecutionTime == nil {
  289. *oldestExecutionTime = &logEntry.DatetimeStarted
  290. } else if logEntry.DatetimeStarted.Before(**oldestExecutionTime) {
  291. *oldestExecutionTime = &logEntry.DatetimeStarted
  292. }
  293. }
  294. // findOldestExecutionInWindow finds the oldest execution within the time window and counts executions.
  295. // Returns the count of executions and the oldest execution time, or nil if none found.
  296. func findOldestExecutionInWindow(logs []*InternalLogEntry, windowStart time.Time) (int, *time.Time) {
  297. executions := 0
  298. var oldestExecutionTime *time.Time
  299. for _, logEntry := range logs {
  300. if !shouldCountExecution(logEntry, windowStart) {
  301. continue
  302. }
  303. executions++
  304. updateOldestExecution(&oldestExecutionTime, logEntry)
  305. }
  306. return executions, oldestExecutionTime
  307. }
  308. // calculateExpiryTime calculates when the oldest execution will fall outside the rate limit window.
  309. func calculateExpiryTime(oldestExecutionTime time.Time, duration time.Duration, now time.Time) time.Time {
  310. expiryTime := oldestExecutionTime.Add(duration)
  311. if !expiryTime.After(now) {
  312. return time.Time{}
  313. }
  314. return expiryTime
  315. }
  316. // updateMaxExpiryTime updates maxExpiryTime if expiryTime is later.
  317. func updateMaxExpiryTime(maxExpiryTime *time.Time, expiryTime time.Time) {
  318. if expiryTime.IsZero() {
  319. return
  320. }
  321. if maxExpiryTime.IsZero() || expiryTime.After(*maxExpiryTime) {
  322. *maxExpiryTime = expiryTime
  323. }
  324. }
  325. // calculateExpiryForRate calculates the expiry time for a single rate limit rule.
  326. // Returns the expiry time if the rate limit is exceeded, or zero time if not.
  327. func calculateExpiryForRate(rate config.RateSpec, logs []*InternalLogEntry, now time.Time) time.Time {
  328. duration := parseDuration(rate)
  329. if duration <= 0 {
  330. return time.Time{}
  331. }
  332. windowStart := now.Add(-duration)
  333. executions, oldestExecutionTime := findOldestExecutionInWindow(logs, windowStart)
  334. if executions < rate.Limit || oldestExecutionTime == nil {
  335. return time.Time{}
  336. }
  337. return calculateExpiryTime(*oldestExecutionTime, duration, now)
  338. }
  339. // getLogsForBinding retrieves logs for a binding ID.
  340. func (e *Executor) getLogsForBinding(bindingId string) []*InternalLogEntry {
  341. e.logmutex.RLock()
  342. logs, found := e.LogsByBindingId[bindingId]
  343. e.logmutex.RUnlock()
  344. if !found || len(logs) == 0 {
  345. return nil
  346. }
  347. return logs
  348. }
  349. // calculateMaxExpiryTimeFromRates calculates the maximum expiry time across all rate limit rules.
  350. func calculateMaxExpiryTimeFromRates(rates []config.RateSpec, logs []*InternalLogEntry, now time.Time) time.Time {
  351. var maxExpiryTime time.Time
  352. for _, rate := range rates {
  353. expiryTime := calculateExpiryForRate(rate, logs, now)
  354. updateMaxExpiryTime(&maxExpiryTime, expiryTime)
  355. }
  356. return maxExpiryTime
  357. }
  358. // GetTimeUntilAvailable calculates when an action will be available again based on rate limits.
  359. // Returns the Unix timestamp in seconds when the rate limit expires, or 0 if the action is available now.
  360. func (e *Executor) GetTimeUntilAvailable(binding *ActionBinding) int64 {
  361. if len(binding.Action.MaxRate) == 0 {
  362. return 0
  363. }
  364. logs := e.getLogsForBinding(binding.ID)
  365. if logs == nil {
  366. return 0
  367. }
  368. maxExpiryTime := calculateMaxExpiryTimeFromRates(binding.Action.MaxRate, logs, time.Now())
  369. if maxExpiryTime.IsZero() {
  370. return 0
  371. }
  372. return maxExpiryTime.Unix()
  373. }
  374. func (e *Executor) SetLog(trackingID string, entry *InternalLogEntry) {
  375. e.logmutex.Lock()
  376. entry.Index = int64(len(e.logsTrackingIdsByDate))
  377. e.logs[trackingID] = entry
  378. e.logsTrackingIdsByDate = append(e.logsTrackingIdsByDate, trackingID)
  379. e.logmutex.Unlock()
  380. }
  381. // ExecRequest processes an ExecutionRequest
  382. func (e *Executor) ExecRequest(req *ExecutionRequest) (*sync.WaitGroup, string) {
  383. if req.AuthenticatedUser == nil {
  384. req.AuthenticatedUser = auth.UserGuest(req.Cfg)
  385. }
  386. req.executor = e
  387. req.logEntry = &InternalLogEntry{
  388. Binding: req.Binding,
  389. DatetimeStarted: time.Now(),
  390. ExecutionTrackingID: req.TrackingID,
  391. Output: "",
  392. ExitCode: DefaultExitCodeNotExecuted,
  393. ExecutionStarted: false,
  394. ExecutionFinished: false,
  395. ActionTitle: "notfound",
  396. ActionIcon: "&#x1f4a9;",
  397. Username: req.AuthenticatedUser.Username,
  398. }
  399. _, isDuplicate := e.GetLog(req.TrackingID)
  400. if isDuplicate || req.TrackingID == "" {
  401. req.TrackingID = uuid.NewString()
  402. }
  403. // Update the log entry with the final tracking ID
  404. req.logEntry.ExecutionTrackingID = req.TrackingID
  405. log.Tracef("executor.ExecRequest(): %v", req)
  406. e.SetLog(req.TrackingID, req.logEntry)
  407. wg := new(sync.WaitGroup)
  408. wg.Add(1)
  409. go func() {
  410. e.execChain(req)
  411. defer wg.Done()
  412. }()
  413. return wg, req.TrackingID
  414. }
  415. func (e *Executor) execChain(req *ExecutionRequest) {
  416. for _, step := range e.chainOfCommand {
  417. if !step(req) {
  418. break
  419. }
  420. }
  421. // Ensure DatetimeFinished is set even if execution was blocked early
  422. if req.logEntry.DatetimeFinished.IsZero() {
  423. req.logEntry.DatetimeFinished = time.Now()
  424. }
  425. req.logEntry.ExecutionFinished = true
  426. // This isn't a step, because we want to notify all listeners, irrespective
  427. // of how many steps were actually executed.
  428. notifyListenersFinished(req)
  429. }
  430. func getConcurrentCount(req *ExecutionRequest) int {
  431. concurrentCount := 0
  432. req.executor.logmutex.RLock()
  433. for _, log := range req.executor.GetLogsByBindingId(req.Binding.ID) {
  434. if !log.ExecutionFinished {
  435. concurrentCount += 1
  436. }
  437. }
  438. req.executor.logmutex.RUnlock()
  439. return concurrentCount
  440. }
  441. func stepConcurrencyCheck(req *ExecutionRequest) bool {
  442. concurrentCount := getConcurrentCount(req)
  443. // Note that the current execution is counted int the logs, so when checking we +1
  444. if concurrentCount >= (req.Binding.Action.MaxConcurrent + 1) {
  445. log.WithFields(log.Fields{
  446. "actionTitle": req.logEntry.ActionTitle,
  447. "concurrentCount": concurrentCount,
  448. "maxConcurrent": req.Binding.Action.MaxConcurrent,
  449. }).Warnf("Blocked from executing due to concurrency limit")
  450. req.logEntry.Output = "Blocked from executing due to concurrency limit"
  451. req.logEntry.Blocked = true
  452. return false
  453. }
  454. return true
  455. }
  456. func parseDuration(rate config.RateSpec) time.Duration {
  457. duration, err := time.ParseDuration(rate.Duration)
  458. if err != nil {
  459. log.Warnf("Could not parse duration: %v", rate.Duration)
  460. return -1 * time.Minute
  461. }
  462. return duration
  463. }
  464. //gocyclo:ignore
  465. func getExecutionsCount(rate config.RateSpec, req *ExecutionRequest) int {
  466. executions := -1 // Because we will find ourself when checking execution logs
  467. duration := parseDuration(rate)
  468. then := time.Now().Add(-duration)
  469. for _, logEntry := range req.executor.GetLogsByBindingId(req.Binding.ID) {
  470. // FIXME
  471. /*
  472. if logEntry.EntityPrefix != req.EntityPrefix {
  473. continue
  474. }
  475. */
  476. if logEntry.DatetimeStarted.After(then) && !logEntry.Blocked {
  477. executions += 1
  478. }
  479. }
  480. return executions
  481. }
  482. func stepRateCheck(req *ExecutionRequest) bool {
  483. for _, rate := range req.Binding.Action.MaxRate {
  484. executions := getExecutionsCount(rate, req)
  485. if executions >= rate.Limit {
  486. log.WithFields(log.Fields{
  487. "actionTitle": req.logEntry.ActionTitle,
  488. "executions": executions,
  489. "limit": rate.Limit,
  490. "duration": rate.Duration,
  491. }).Infof("Blocked from executing due to rate limit")
  492. req.logEntry.Output = "Blocked from executing due to rate limit"
  493. req.logEntry.Blocked = true
  494. return false
  495. }
  496. }
  497. return true
  498. }
  499. func stepACLCheck(req *ExecutionRequest) bool {
  500. canExec := acl.IsAllowedExec(req.Cfg, req.AuthenticatedUser, req.Binding.Action)
  501. if !canExec {
  502. req.logEntry.Output = "ACL check failed. Blocked from executing."
  503. req.logEntry.Blocked = true
  504. log.WithFields(log.Fields{
  505. "actionTitle": req.logEntry.ActionTitle,
  506. }).Warnf("ACL check failed. Blocked from executing.")
  507. }
  508. return canExec
  509. }
  510. func stepParseArgs(req *ExecutionRequest) bool {
  511. ensureArgumentMap(req)
  512. injectSystemArgs(req)
  513. if !hasBindingAndAction(req) {
  514. return fail(req, fmt.Errorf("cannot parse arguments: Binding or Action is nil"))
  515. }
  516. mangleInvalidArgumentValues(req)
  517. if hasExec(req) {
  518. return handleExecBranch(req)
  519. } else {
  520. return handleShellBranch(req)
  521. }
  522. }
  523. func handleExecBranch(req *ExecutionRequest) bool {
  524. args, err := parseActionExec(req.Arguments, req.Binding.Action, req.Binding.Entity)
  525. if err != nil {
  526. return fail(req, err)
  527. }
  528. req.useDirectExec = true
  529. req.execArgs = args
  530. return true
  531. }
  532. func handleShellBranch(req *ExecutionRequest) bool {
  533. if err := checkShellArgumentSafety(req.Binding.Action); err != nil {
  534. return fail(req, err)
  535. }
  536. cmd, err := parseActionArguments(req.Arguments, req.Binding.Action, req.Binding.Entity)
  537. if err != nil {
  538. return fail(req, err)
  539. }
  540. req.useDirectExec = false
  541. req.finalParsedCommand = cmd
  542. return true
  543. }
  544. func ensureArgumentMap(req *ExecutionRequest) {
  545. if req.Arguments == nil {
  546. req.Arguments = make(map[string]string)
  547. }
  548. }
  549. func injectSystemArgs(req *ExecutionRequest) {
  550. req.Arguments["ot_executionTrackingId"] = req.TrackingID
  551. req.Arguments["ot_username"] = req.AuthenticatedUser.Username
  552. }
  553. func hasBindingAndAction(req *ExecutionRequest) bool {
  554. return !(req.Binding == nil || req.Binding.Action == nil)
  555. }
  556. func hasExec(req *ExecutionRequest) bool {
  557. return len(req.Binding.Action.Exec) > 0
  558. }
  559. func fail(req *ExecutionRequest, err error) bool {
  560. req.logEntry.Output = err.Error()
  561. log.Warn(err.Error())
  562. return false
  563. }
  564. func stepRequestAction(req *ExecutionRequest) bool {
  565. metricActionsRequested.Inc()
  566. // If there is no binding or action, do not proceed. Leave default
  567. // log entry values (icon/title/id) and stop execution gracefully.
  568. if req.Binding == nil || req.Binding.Action == nil {
  569. log.Warnf("Action request has no binding/action; skipping execution")
  570. return false
  571. }
  572. req.logEntry.Binding = req.Binding
  573. req.logEntry.ActionConfigTitle = req.Binding.Action.Title
  574. req.logEntry.ActionTitle = tpl.ParseTemplateWith(req.Binding.Action.Title, req.Binding.Entity)
  575. req.logEntry.ActionIcon = req.Binding.Action.Icon
  576. req.logEntry.Tags = req.Tags
  577. req.executor.logmutex.Lock()
  578. if _, containsKey := req.executor.LogsByBindingId[req.Binding.ID]; !containsKey {
  579. req.executor.LogsByBindingId[req.Binding.ID] = make([]*InternalLogEntry, 0)
  580. }
  581. req.executor.LogsByBindingId[req.Binding.ID] = append(req.executor.LogsByBindingId[req.Binding.ID], req.logEntry)
  582. req.executor.logmutex.Unlock()
  583. log.WithFields(log.Fields{
  584. "actionTitle": req.logEntry.ActionTitle,
  585. "tags": req.Tags,
  586. }).Infof("Action requested")
  587. notifyListenersStarted(req)
  588. return true
  589. }
  590. func stepLogStart(req *ExecutionRequest) bool {
  591. log.WithFields(log.Fields{
  592. "actionTitle": req.logEntry.ActionTitle,
  593. "timeout": req.Binding.Action.Timeout,
  594. }).Infof("Action started")
  595. return true
  596. }
  597. func stepLogFinish(req *ExecutionRequest) bool {
  598. req.logEntry.ExecutionFinished = true
  599. log.WithFields(log.Fields{
  600. "actionTitle": req.logEntry.ActionTitle,
  601. "outputLength": len(req.logEntry.Output),
  602. "timedOut": req.logEntry.TimedOut,
  603. "exit": req.logEntry.ExitCode,
  604. }).Infof("Action finished")
  605. return true
  606. }
  607. func notifyListenersFinished(req *ExecutionRequest) {
  608. for _, listener := range req.executor.listeners {
  609. listener.OnExecutionFinished(req.logEntry)
  610. }
  611. }
  612. func notifyListenersStarted(req *ExecutionRequest) {
  613. for _, listener := range req.executor.listeners {
  614. listener.OnExecutionStarted(req.logEntry)
  615. }
  616. }
  617. func appendErrorToStderr(err error, logEntry *InternalLogEntry) {
  618. if err != nil {
  619. logEntry.Output = err.Error() + "\n\n" + logEntry.Output
  620. }
  621. }
  622. type OutputStreamer struct {
  623. Req *ExecutionRequest
  624. output bytes.Buffer
  625. }
  626. func (ost *OutputStreamer) Write(o []byte) (n int, err error) {
  627. for _, listener := range ost.Req.executor.listeners {
  628. listener.OnOutputChunk(o, ost.Req.TrackingID)
  629. }
  630. return ost.output.Write(o)
  631. }
  632. func (ost *OutputStreamer) String() string {
  633. return ost.output.String()
  634. }
  635. func buildEnv(args map[string]string) []string {
  636. ret := append(os.Environ(), "OLIVETIN=1")
  637. for k, v := range args {
  638. varName := fmt.Sprintf("%v", strings.TrimSpace(strings.ToUpper(k)))
  639. // Skip arguments that might not have a name (eg, confirmation), as this causes weird bugs on Windows.
  640. if varName == "" {
  641. continue
  642. }
  643. ret = append(ret, fmt.Sprintf("%v=%v", varName, v))
  644. }
  645. return ret
  646. }
  647. func stepExec(req *ExecutionRequest) bool {
  648. ctx, cancel := newTimeoutContext(context.Background(), time.Duration(req.Binding.Action.Timeout)*time.Second, req.executor)
  649. defer cancel()
  650. streamer := &OutputStreamer{Req: req}
  651. cmd := buildCommand(ctx, req)
  652. if cmd == nil {
  653. req.logEntry.Output = "Cannot execute: no command arguments provided"
  654. log.Warn("Cannot execute: no command arguments provided")
  655. return false
  656. }
  657. prepareCommand(cmd, streamer, req)
  658. runerr := cmd.Start()
  659. req.logEntry.Process = cmd.Process
  660. ctx.setProcess(cmd.Process)
  661. waiterr := cmd.Wait()
  662. req.logEntry.ExitCode = int32(cmd.ProcessState.ExitCode())
  663. req.logEntry.Output = streamer.String()
  664. appendErrorToStderr(runerr, req.logEntry)
  665. appendErrorToStderr(waiterr, req.logEntry)
  666. if ctx.Err() == context.DeadlineExceeded {
  667. log.WithFields(log.Fields{
  668. "actionTitle": req.logEntry.ActionTitle,
  669. }).Warnf("Action timed out")
  670. req.logEntry.TimedOut = true
  671. req.logEntry.Output += "OliveTin::timeout - this action timed out after " + fmt.Sprintf("%v", req.Binding.Action.Timeout) + " seconds. If you need more time for this action, set a longer timeout. See https://docs.olivetin.app/action_customization/timeouts.html for more help."
  672. }
  673. req.logEntry.DatetimeFinished = time.Now()
  674. return true
  675. }
  676. func buildCommand(ctx context.Context, req *ExecutionRequest) *exec.Cmd {
  677. if req.useDirectExec {
  678. return wrapCommandDirect(ctx, req.execArgs)
  679. }
  680. return wrapCommandInShell(ctx, req.finalParsedCommand)
  681. }
  682. func prepareCommand(cmd *exec.Cmd, streamer *OutputStreamer, req *ExecutionRequest) {
  683. cmd.Stdout = streamer
  684. cmd.Stderr = streamer
  685. cmd.Env = buildEnv(req.Arguments)
  686. req.logEntry.ExecutionStarted = true
  687. }
  688. func stepExecAfter(req *ExecutionRequest) bool {
  689. if req.Binding.Action.ShellAfterCompleted == "" {
  690. return true
  691. }
  692. ctx, cancel := newTimeoutContext(context.Background(), time.Duration(req.Binding.Action.Timeout)*time.Second, req.executor)
  693. defer cancel()
  694. var stdout bytes.Buffer
  695. var stderr bytes.Buffer
  696. args := map[string]string{
  697. "output": req.logEntry.Output,
  698. "exitCode": fmt.Sprintf("%v", req.logEntry.ExitCode),
  699. "ot_executionTrackingId": req.TrackingID,
  700. "ot_username": req.AuthenticatedUser.Username,
  701. }
  702. finalParsedCommand, err := parseCommandForReplacements(req.Binding.Action.ShellAfterCompleted, args, req.Binding.Entity)
  703. if err != nil {
  704. msg := "Could not prepare shellAfterCompleted command: " + err.Error() + "\n"
  705. req.logEntry.Output += msg
  706. log.Warn(msg)
  707. return true
  708. }
  709. cmd := wrapCommandInShell(ctx, finalParsedCommand)
  710. cmd.Stdout = &stdout
  711. cmd.Stderr = &stderr
  712. cmd.Env = buildEnv(args)
  713. runerr := cmd.Start()
  714. ctx.setProcess(cmd.Process)
  715. waiterr := cmd.Wait()
  716. req.logEntry.Output += "\n"
  717. req.logEntry.Output += "OliveTin::shellAfterCompleted stdout\n"
  718. req.logEntry.Output += stdout.String()
  719. req.logEntry.Output += "OliveTin::shellAfterCompleted stderr\n"
  720. req.logEntry.Output += stderr.String()
  721. req.logEntry.Output += "OliveTin::shellAfterCompleted errors and summary\n"
  722. appendErrorToStderr(runerr, req.logEntry)
  723. appendErrorToStderr(waiterr, req.logEntry)
  724. if ctx.Err() == context.DeadlineExceeded {
  725. req.logEntry.Output += "Your shellAfterCompleted command timed out."
  726. }
  727. req.logEntry.Output += fmt.Sprintf("Your shellAfterCompleted exited with code %v\n", cmd.ProcessState.ExitCode())
  728. req.logEntry.Output += "OliveTin::shellAfterCompleted output complete\n"
  729. return true
  730. }
  731. //gocyclo:ignore
  732. func stepTrigger(req *ExecutionRequest) bool {
  733. if req.Binding.Action.Triggers == nil {
  734. return true
  735. }
  736. if req.TriggerDepth >= MaxTriggerDepth {
  737. log.WithFields(log.Fields{
  738. "actionTitle": req.logEntry.ActionTitle,
  739. "depth": req.TriggerDepth,
  740. }).Warnf("Trigger action reached maximum depth of %v. Not triggering further actions.", MaxTriggerDepth)
  741. req.logEntry.Output += fmt.Sprintf("OliveTin::trigger - this action reached maximum trigger depth of %v. Not triggering further actions.", MaxTriggerDepth)
  742. return true
  743. }
  744. if len(req.Tags) > 0 && req.Tags[0] == "trigger" {
  745. log.Warnf("Trigger action is triggering another trigger action. This is allowed, but be careful not to create trigger loops.")
  746. }
  747. triggerLoop(req)
  748. return true
  749. }
  750. func triggerLoop(req *ExecutionRequest) {
  751. for _, triggerReq := range req.Binding.Action.Triggers {
  752. binding := req.executor.FindBindingByID(triggerReq)
  753. trigger := &ExecutionRequest{
  754. Binding: binding,
  755. TrackingID: uuid.NewString(),
  756. Tags: []string{"trigger"},
  757. AuthenticatedUser: req.AuthenticatedUser,
  758. Arguments: req.Arguments,
  759. Cfg: req.Cfg,
  760. TriggerDepth: req.TriggerDepth + 1,
  761. }
  762. req.executor.ExecRequest(trigger)
  763. }
  764. }
  765. func stepSaveLog(req *ExecutionRequest) bool {
  766. filename := fmt.Sprintf("%v.%v.%v", req.logEntry.ActionTitle, req.logEntry.DatetimeStarted.Unix(), req.logEntry.ExecutionTrackingID)
  767. saveLogResults(req, filename)
  768. saveLogOutput(req, filename)
  769. return true
  770. }
  771. func firstNonEmpty(one, two string) string {
  772. if one != "" {
  773. return one
  774. }
  775. return two
  776. }
  777. func saveLogResults(req *ExecutionRequest, filename string) {
  778. dir := firstNonEmpty(req.Binding.Action.SaveLogs.ResultsDirectory, req.Cfg.SaveLogs.ResultsDirectory)
  779. if dir != "" {
  780. data, err := yaml.Marshal(req.logEntry)
  781. if err != nil {
  782. log.Warnf("%v", err)
  783. }
  784. filepath := path.Join(dir, filename+".yaml")
  785. err = os.WriteFile(filepath, data, 0644)
  786. if err != nil {
  787. log.Warnf("%v", err)
  788. }
  789. }
  790. }
  791. func saveLogOutput(req *ExecutionRequest, filename string) {
  792. dir := firstNonEmpty(req.Binding.Action.SaveLogs.OutputDirectory, req.Cfg.SaveLogs.OutputDirectory)
  793. if dir != "" {
  794. data := req.logEntry.Output
  795. filepath := path.Join(dir, filename+".log")
  796. err := os.WriteFile(filepath, []byte(data), 0644)
  797. if err != nil {
  798. log.Warnf("%v", err)
  799. }
  800. }
  801. }